[Spice-devel] [PATCH server 0.8 1/3] server: introduce red_log and red_warn
Marc-André Lureau
marcandre.lureau at gmail.com
Sun Oct 9 09:37:30 PDT 2011
Hi
On Sun, Oct 9, 2011 at 4:29 PM, Alon Levy <alevy at redhat.com> wrote:
> change all red_printf variants to call red_log, including red_warn.
> Introduce a static (per compile unit) spice_log_level, settable on
> first access (via get_spice_log_level) from the environment variable
> SPICE_LOG_LEVEL (we already have SPICEC_LOG_LEVEL and spice-gtk has
> SPICE_DEBUG, though much more verbose and useful, but relying on glib).
>
> This might seem like a waste of time if we move to glib, but we haven't
> yet and I want the ability to add prints that are not on by default into
> the code base (as opposed to locally for each developer).
As we discussed on IRC, I think changing logging is fairly easy, so as
long as it call a function such as red_warn ("blah blah"); It's easy
to move to use something else in the future.
However, red_log(2, "blah"); is bad for several reasons. Why not use
red_debug()?
> ---
> server/agent-msg-filter.c | 8 +-
> server/red_channel.c | 12 +-
> server/red_common.h | 45 ++++-
> server/red_dispatcher.c | 19 +-
> server/red_tunnel_worker.c | 142 ++++++++--------
> server/red_worker.c | 160 +++++++++---------
> server/reds.c | 372 +++++++++++++++++++-------------------
> server/smartcard.c | 14 +-
> server/snd_worker.c | 42 +++---
> server/tests/basic_event_loop.c | 1 +
> server/zlib_encoder.c | 2 +-
> 11 files changed, 426 insertions(+), 391 deletions(-)
>
> diff --git a/server/agent-msg-filter.c b/server/agent-msg-filter.c
> index cd1f78c..afa0f76 100644
> --- a/server/agent-msg-filter.c
> +++ b/server/agent-msg-filter.c
> @@ -36,7 +36,7 @@ int agent_msg_filter_process_data(struct AgentMsgFilter *filter,
> struct VDAgentMessage msg_header;
>
> if (len > VD_AGENT_MAX_DATA_SIZE) {
> - red_printf("invalid agent message: too large");
> + red_warn("invalid agent message: too large");
> return AGENT_MSG_FILTER_PROTO_ERROR;
> }
>
> @@ -44,7 +44,7 @@ int agent_msg_filter_process_data(struct AgentMsgFilter *filter,
> if (filter->msg_data_to_read) {
> data_to_read:
> if (len > filter->msg_data_to_read) {
> - red_printf("invalid agent message: data exceeds size from header");
> + red_warn("invalid agent message: data exceeds size from header");
> return AGENT_MSG_FILTER_PROTO_ERROR;
> }
> filter->msg_data_to_read -= len;
> @@ -52,14 +52,14 @@ data_to_read:
> }
>
> if (len < sizeof(msg_header)) {
> - red_printf("invalid agent message: incomplete header");
> + red_warn("invalid agent message: incomplete header");
> return AGENT_MSG_FILTER_PROTO_ERROR;
> }
> memcpy(&msg_header, data, sizeof(msg_header));
> len -= sizeof(msg_header);
>
> if (msg_header.protocol != VD_AGENT_PROTOCOL) {
> - red_printf("invalid agent protocol: %u", msg_header.protocol);
> + red_warn("invalid agent protocol: %u", msg_header.protocol);
> return AGENT_MSG_FILTER_PROTO_ERROR;
> }
>
> diff --git a/server/red_channel.c b/server/red_channel.c
> index da0fb9f..b7c0db5 100644
> --- a/server/red_channel.c
> +++ b/server/red_channel.c
> @@ -55,7 +55,7 @@ static int red_peer_receive(RedsStream *stream, uint8_t *buf, uint32_t size)
> } else if (errno == EPIPE) {
> return -1;
> } else {
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> return -1;
> }
> } else {
> @@ -91,7 +91,7 @@ static void red_peer_handle_incoming(RedsStream *stream, IncomingHandler *handle
> if (!handler->msg) {
> handler->msg = handler->alloc_msg_buf(handler->opaque, &handler->header);
> if (handler->msg == NULL) {
> - red_printf("ERROR: channel refused to allocate buffer.");
> + red_warn("ERROR: channel refused to allocate buffer.");
> handler->on_error(handler->opaque);
> return;
> }
> @@ -165,7 +165,7 @@ static void red_peer_handle_outgoing(RedsStream *stream, OutgoingHandler *handle
> handler->on_error(handler->opaque);
> return;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> handler->on_error(handler->opaque);
> return;
> }
> @@ -314,7 +314,7 @@ void red_channel_destroy(RedChannel *channel)
>
> void red_channel_shutdown(RedChannel *channel)
> {
> - red_printf("");
> + red_log(2, "");
> if (channel->stream && !channel->stream->shutdown) {
> channel->core->watch_update_mask(channel->stream->watch,
> SPICE_WATCH_EVENT_READ);
> @@ -335,7 +335,7 @@ int red_channel_handle_message(RedChannel *channel, SpiceDataHeader *header, uin
> switch (header->type) {
> case SPICE_MSGC_ACK_SYNC:
> if (header->size != sizeof(uint32_t)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
> channel->ack_data.client_generation = *(uint32_t *)(msg);
> @@ -347,7 +347,7 @@ int red_channel_handle_message(RedChannel *channel, SpiceDataHeader *header, uin
> }
> break;
> default:
> - red_printf("invalid message type %u", header->type);
> + red_warn("invalid message type %u", header->type);
> return FALSE;
> }
> return TRUE;
> diff --git a/server/red_common.h b/server/red_common.h
> index c863922..c060495 100644
> --- a/server/red_common.h
> +++ b/server/red_common.h
> @@ -26,6 +26,31 @@
> #include <messages.h>
> #include <spice/macros.h>
>
> +#define LOG_INVALID -1
> +#define LOG_NONE 0
> +#define LOG_WARN 1
> +/* anything higher is not defined */
> +
> +#define SPICE_DEFAULT_LOG_LEVEL LOG_WARN
> +
> +static int spice_log_level = LOG_INVALID;
> +
> +static inline int get_spice_log_level(void) {
> + char *log_level;
> +
> + if (spice_log_level != LOG_INVALID) {
> + return spice_log_level;
> + }
> + log_level = getenv("SPICE_LOG_LEVEL");
> +
> + if (log_level == NULL) {
> + spice_log_level = SPICE_DEFAULT_LOG_LEVEL;
> + } else {
> + spice_log_level = atoi(log_level);
> + }
> + return spice_log_level;
> +}
> +
> #define ASSERT(x) if (!(x)) { \
> printf("%s: ASSERT %s failed\n", __FUNCTION__, #x); \
> abort(); \
> @@ -46,23 +71,29 @@
> abort(); \
> }
>
> -#define red_printf(format, ...) \
> - printf("%s: " format "\n", __FUNCTION__, ## __VA_ARGS__ )
> +#define red_warn(format, ...) red_log(LOG_WARN, format, ## __VA_ARGS__)
>
> -#define red_printf_once(format, ...) { \
> +#define red_log(level, format, ...) \
> + do { \
> + if (level <= get_spice_log_level()) { \
> + printf("spice(%d) %s: " format "\n", level, __FUNCTION__, ## __VA_ARGS__ ); \
> + } \
> + } while (0)
> +
> +#define red_log_once(level, format, ...) { \
> static int do_print = TRUE; \
> if (do_print) { \
> do_print = FALSE; \
> - printf("%s: " format "\n", __FUNCTION__, ## __VA_ARGS__ ); \
> + red_log(level, "%s: " format "\n", __FUNCTION__, ## __VA_ARGS__ ); \
> } \
> }
>
> -#define red_printf_some(every, format, ...) { \
> +#define red_log_some(level, every, format, ...) do { \
> static int count = 0; \
> if (count++ % (every) == 0) { \
> - printf("%s: " format "\n", __FUNCTION__, ## __VA_ARGS__ ); \
> + red_log(level, "%s: " format "\n", __FUNCTION__, ## __VA_ARGS__ ); \
> } \
> -}
> +} while (0)
>
> enum {
> STREAM_VIDEO_INVALID,
> diff --git a/server/red_dispatcher.c b/server/red_dispatcher.c
> index f74b13e..f846a8c 100644
> --- a/server/red_dispatcher.c
> +++ b/server/red_dispatcher.c
> @@ -79,7 +79,7 @@ static void red_dispatcher_set_peer(Channel *channel, RedsStream *stream, int mi
> {
> RedDispatcher *dispatcher;
>
> - red_printf("");
> + red_log(2, "");
> dispatcher = (RedDispatcher *)channel->data;
> RedWorkerMessage message = RED_WORKER_MESSAGE_DISPLAY_CONNECT;
> write_message(dispatcher->channel, &message);
> @@ -90,7 +90,7 @@ static void red_dispatcher_set_peer(Channel *channel, RedsStream *stream, int mi
> static void red_dispatcher_shutdown_peer(Channel *channel)
> {
> RedDispatcher *dispatcher = (RedDispatcher *)channel->data;
> - red_printf("");
> + red_log(2, "");
> RedWorkerMessage message = RED_WORKER_MESSAGE_DISPLAY_DISCONNECT;
> write_message(dispatcher->channel, &message);
> }
> @@ -98,7 +98,7 @@ static void red_dispatcher_shutdown_peer(Channel *channel)
> static void red_dispatcher_migrate(Channel *channel)
> {
> RedDispatcher *dispatcher = (RedDispatcher *)channel->data;
> - red_printf("channel type %u id %u", channel->type, channel->id);
> + red_log(2, "channel type %u id %u", channel->type, channel->id);
> RedWorkerMessage message = RED_WORKER_MESSAGE_DISPLAY_MIGRATE;
> write_message(dispatcher->channel, &message);
> }
> @@ -109,7 +109,7 @@ static void red_dispatcher_set_cursor_peer(Channel *channel, RedsStream *stream,
> uint32_t *caps)
> {
> RedDispatcher *dispatcher = (RedDispatcher *)channel->data;
> - red_printf("");
> + red_log(2, "");
> RedWorkerMessage message = RED_WORKER_MESSAGE_CURSOR_CONNECT;
> write_message(dispatcher->channel, &message);
> send_data(dispatcher->channel, &stream, sizeof(RedsStream *));
> @@ -119,7 +119,7 @@ static void red_dispatcher_set_cursor_peer(Channel *channel, RedsStream *stream,
> static void red_dispatcher_shutdown_cursor_peer(Channel *channel)
> {
> RedDispatcher *dispatcher = (RedDispatcher *)channel->data;
> - red_printf("");
> + red_log(2, "");
> RedWorkerMessage message = RED_WORKER_MESSAGE_CURSOR_DISCONNECT;
> write_message(dispatcher->channel, &message);
> }
> @@ -127,7 +127,7 @@ static void red_dispatcher_shutdown_cursor_peer(Channel *channel)
> static void red_dispatcher_cursor_migrate(Channel *channel)
> {
> RedDispatcher *dispatcher = (RedDispatcher *)channel->data;
> - red_printf("channel type %u id %u", channel->type, channel->id);
> + red_log(2, "channel type %u id %u", channel->type, channel->id);
> RedWorkerMessage message = RED_WORKER_MESSAGE_CURSOR_MIGRATE;
> write_message(dispatcher->channel, &message);
> }
> @@ -229,7 +229,8 @@ static RedWorkerMessage red_dispatcher_async_start(RedDispatcher *dispatcher,
> {
> pthread_mutex_lock(&dispatcher->async_lock);
> if (dispatcher->async_message != RED_WORKER_MESSAGE_NOP) {
> - red_printf("error: async clash. second async ignored");
> + red_warn("warning: async clash. have %d, ignoring %d",
> + dispatcher->async_message, message);
> pthread_mutex_unlock(&dispatcher->async_lock);
> return RED_WORKER_MESSAGE_NOP;
> }
> @@ -570,7 +571,7 @@ static void red_dispatcher_loadvm_commands(RedDispatcher *dispatcher,
> {
> RedWorkerMessage message = RED_WORKER_MESSAGE_LOADVM_COMMANDS;
>
> - red_printf("");
> + red_log(2, "");
> write_message(dispatcher->channel, &message);
> send_data(dispatcher->channel, &count, sizeof(uint32_t));
> send_data(dispatcher->channel, ext, sizeof(QXLCommandExt) * count);
> @@ -824,7 +825,7 @@ void red_dispatcher_async_complete(struct RedDispatcher *dispatcher, uint64_t co
> case RED_WORKER_MESSAGE_FLUSH_SURFACES_ASYNC:
> break;
> default:
> - red_printf("unexpected message");
> + red_warn("unexpected message");
> }
> dispatcher->async_message = RED_WORKER_MESSAGE_NOP;
> pthread_mutex_unlock(&dispatcher->async_lock);
> diff --git a/server/red_tunnel_worker.c b/server/red_tunnel_worker.c
> index 46cccb5..b90f253 100644
> --- a/server/red_tunnel_worker.c
> +++ b/server/red_tunnel_worker.c
> @@ -41,7 +41,7 @@
> //#define DEBUG_NETWORK
>
> #ifdef DEBUG_NETWORK
> -#define PRINT_SCKT(sckt) red_printf("TUNNEL_DBG SOCKET(connection_id=%d port=%d, service=%d)",\
> +#define PRINT_SCKT(sckt) red_log(2, "TUNNEL_DBG SOCKET(connection_id=%d port=%d, service=%d)",\
> sckt->connection_id, ntohs(sckt->local_port), \
> sckt->far_service->id)
> #endif
> @@ -477,7 +477,7 @@ static inline void tunnel_channel_activate_migrated_sockets(TunnelChannel *chann
> failed (which triggered from a call to slirp) */
> #define SET_TUNNEL_ERROR(channel,format, ...) { \
> channel->tunnel_error = TRUE; \
> - red_printf(format, ## __VA_ARGS__); \
> + red_warn(format, ## __VA_ARGS__); \
> }
>
> /* should be checked after each subroutine that may cause error or after calls to slirp routines */
> @@ -608,7 +608,8 @@ static void handle_tunnel_channel_migrate(struct Channel *channel);
> static void tunnel_shutdown(TunnelWorker *worker)
> {
> int i;
> - red_printf("");
> +
> + red_log(2, "");
> /* shutdown input from channel */
> if (worker->channel) {
> red_channel_shutdown(&worker->channel->base);
> @@ -1054,7 +1055,7 @@ static inline TunnelService *__tunnel_worker_add_service(TunnelWorker *worker, u
> TunnelService *service_of_same_group;
> if (!(service_of_same_group = __tunnel_worker_find_service_of_group(worker, group))) {
> if (!net_slirp_allocate_virtual_ip(&new_service->virt_ip)) {
> - red_printf("failed to allocate virtual ip");
> + red_warn("failed to allocate virtual ip");
> free(new_service);
> return NULL;
> }
> @@ -1062,7 +1063,7 @@ static inline TunnelService *__tunnel_worker_add_service(TunnelWorker *worker, u
> if (strcmp(name, service_of_same_group->name) == 0) {
> new_service->virt_ip.s_addr = service_of_same_group->virt_ip.s_addr;
> } else {
> - red_printf("inconsistent name for service group %d", group);
> + red_warn("inconsistent name for service group %d", group);
> free(new_service);
> return NULL;
> }
> @@ -1084,7 +1085,7 @@ static inline TunnelService *__tunnel_worker_add_service(TunnelWorker *worker, u
> worker->num_services++;
>
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL_DBG: ==>SERVICE ADDED: id=%d virt ip=%s port=%d name=%s desc=%s",
> + red_log(2, "TUNNEL_DBG: ==>SERVICE ADDED: id=%d virt ip=%s port=%d name=%s desc=%s",
> new_service->id, inet_ntoa(new_service->virt_ip),
> new_service->port, new_service->name, new_service->description);
> #endif
> @@ -1137,12 +1138,12 @@ static TunnelPrintService *tunnel_worker_add_print_service(TunnelWorker *worker,
> if (redc_service->type == SPICE_TUNNEL_IP_TYPE_IPv4) {
> memcpy(service->ip, redc_service->u.ip.data, sizeof(SpiceTunnelIPv4));
> } else {
> - red_printf("unexpected ip type=%d", redc_service->type);
> + red_warn("unexpected ip type=%d", redc_service->type);
> tunnel_worker_free_print_service(worker, service);
> return NULL;
> }
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL_DBG: ==>PRINT SERVICE ADDED: ip=%d.%d.%d.%d", service->ip[0],
> + red_log(2, "TUNNEL_DBG: ==>PRINT SERVICE ADDED: ip=%d.%d.%d.%d", service->ip[0],
> service->ip[1], service->ip[2], service->ip[3]);
> #endif
> return service;
> @@ -1159,7 +1160,7 @@ static int tunnel_channel_handle_service_add(TunnelChannel *channel,
> out_service = tunnel_worker_add_service(channel->worker, sizeof(TunnelService),
> service_msg);
> } else {
> - red_printf("invalid service type");
> + red_warn("invalid service type");
> }
>
> free(service_msg);
> @@ -1412,7 +1413,7 @@ static int tunnel_channel_handle_socket_connect_ack(TunnelChannel *channel, RedS
> uint32_t tokens)
> {
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL_DBG");
> + red_log(2, "TUNNEL_DBG");
> #endif
> if (channel->mig_inprogress || channel->base.migrate) {
> sckt->mig_client_status_msg = SPICE_MSGC_TUNNEL_SOCKET_OPEN_ACK;
> @@ -1421,7 +1422,7 @@ static int tunnel_channel_handle_socket_connect_ack(TunnelChannel *channel, RedS
> }
>
> if (sckt->client_status != CLIENT_SCKT_STATUS_WAIT_OPEN) {
> - red_printf("unexpected SPICE_MSGC_TUNNEL_SOCKET_OPEN_ACK status=%d", sckt->client_status);
> + red_warn("unexpected SPICE_MSGC_TUNNEL_SOCKET_OPEN_ACK status=%d", sckt->client_status);
> return FALSE;
> }
> sckt->client_status = CLIENT_SCKT_STATUS_OPEN;
> @@ -1435,7 +1436,7 @@ static int tunnel_channel_handle_socket_connect_ack(TunnelChannel *channel, RedS
> sckt->out_data.num_tokens = tokens;
> net_slirp_socket_connected_notify(sckt->slirp_sckt);
> } else {
> - red_printf("unexpected slirp status status=%d", sckt->slirp_status);
> + red_warn("unexpected slirp status status=%d", sckt->slirp_status);
> return FALSE;
> }
>
> @@ -1453,7 +1454,7 @@ static int tunnel_channel_handle_socket_connect_nack(TunnelChannel *channel, Red
> }
>
> if (sckt->client_status != CLIENT_SCKT_STATUS_WAIT_OPEN) {
> - red_printf("unexpected SPICE_MSGC_TUNNEL_SOCKET_OPEN_NACK status=%d", sckt->client_status);
> + red_warn("unexpected SPICE_MSGC_TUNNEL_SOCKET_OPEN_NACK status=%d", sckt->client_status);
> return FALSE;
> }
> sckt->client_status = CLIENT_SCKT_STATUS_CLOSED;
> @@ -1478,7 +1479,7 @@ static int tunnel_channel_handle_socket_fin(TunnelChannel *channel, RedSocket *s
> }
>
> if (sckt->client_status != CLIENT_SCKT_STATUS_OPEN) {
> - red_printf("unexpected SPICE_MSGC_TUNNEL_SOCKET_FIN status=%d", sckt->client_status);
> + red_warn("unexpected SPICE_MSGC_TUNNEL_SOCKET_FIN status=%d", sckt->client_status);
> return FALSE;
> }
> sckt->client_status = CLIENT_SCKT_STATUS_SHUTDOWN_SEND;
> @@ -1495,7 +1496,7 @@ static int tunnel_channel_handle_socket_fin(TunnelChannel *channel, RedSocket *s
> net_slirp_socket_can_receive_notify(sckt->slirp_sckt);
> } else if (sckt->slirp_status == SLIRP_SCKT_STATUS_SHUTDOWN_RECV) {
> // it already received the FIN
> - red_printf("unexpected slirp status=%d", sckt->slirp_status);
> + red_warn("unexpected slirp status=%d", sckt->slirp_status);
> return FALSE;
> }
>
> @@ -1544,7 +1545,7 @@ static int tunnel_channel_handle_socket_closed(TunnelChannel *channel, RedSocket
> // slirp can be in wait close if both slirp and client sent fin previously
> // otherwise, the prev client status would also have been wait close, and this
> // case was handled above
> - red_printf("unexpected slirp_status=%d", sckt->slirp_status);
> + red_warn("unexpected slirp_status=%d", sckt->slirp_status);
> return FALSE;
> }
>
> @@ -1569,8 +1570,8 @@ static int tunnel_channel_handle_socket_closed_ack(TunnelChannel *channel, RedSo
> }
>
> if (sckt->slirp_status != SLIRP_SCKT_STATUS_CLOSED) {
> - red_printf("unexpected SPICE_MSGC_TUNNEL_SOCKET_CLOSED_ACK slirp_status=%d",
> - sckt->slirp_status);
> + red_warn("unexpected SPICE_MSGC_TUNNEL_SOCKET_CLOSED_ACK slirp_status=%d",
> + sckt->slirp_status);
> return FALSE;
> }
>
> @@ -1583,8 +1584,8 @@ static int tunnel_channel_handle_socket_receive_data(TunnelChannel *channel, Red
> {
> if ((sckt->client_status == CLIENT_SCKT_STATUS_SHUTDOWN_SEND) ||
> (sckt->client_status == CLIENT_SCKT_STATUS_CLOSED)) {
> - red_printf("unexpected SPICE_MSGC_TUNNEL_SOCKET_DATA client_status=%d",
> - sckt->client_status);
> + red_warn("unexpected SPICE_MSGC_TUNNEL_SOCKET_DATA client_status=%d",
> + sckt->client_status);
> return FALSE;
> }
>
> @@ -1595,9 +1596,9 @@ static int tunnel_channel_handle_socket_receive_data(TunnelChannel *channel, Red
> return (!CHECK_TUNNEL_ERROR(channel));
> } else if ((sckt->in_data.num_buffers == MAX_SOCKET_IN_BUFFERS) &&
> !channel->mig_inprogress && !channel->base.migrate) {
> - red_printf("socket in buffers overflow, socket will be closed"
> - " (local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port), sckt->far_service->id);
> + red_warn("socket in buffers overflow, socket will be closed"
> + " (local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port), sckt->far_service->id);
> __tunnel_worker_free_socket_rcv_buf(sckt->worker, recv_data);
> tunnel_socket_force_close(channel, sckt);
> return (!CHECK_TUNNEL_ERROR(channel));
> @@ -1605,7 +1606,7 @@ static int tunnel_channel_handle_socket_receive_data(TunnelChannel *channel, Red
>
> tunnel_socket_assign_rcv_buf(sckt, recv_data, buf_size);
> if (!sckt->in_data.client_total_num_tokens) {
> - red_printf("token violation");
> + red_warn("token violation");
> return FALSE;
> }
>
> @@ -1749,7 +1750,7 @@ static int tunnel_channel_handle_migrate_mark(TunnelChannel *channel)
> RedSocket *sckt;
>
> if (!channel->expect_migrate_mark) {
> - red_printf("unexpected");
> + red_warn("unexpected");
> return FALSE;
> }
> channel->expect_migrate_mark = FALSE;
> @@ -1758,7 +1759,7 @@ static int tunnel_channel_handle_migrate_mark(TunnelChannel *channel)
>
> migrate_item->slirp_state_size = net_slirp_state_export(&migrate_item->slirp_state);
> if (!migrate_item->slirp_state) {
> - red_printf("failed export slirp state");
> + red_warn("failed export slirp state");
> goto error;
> }
>
> @@ -1891,7 +1892,7 @@ RawTunneledBuffer *__tunnel_socket_alloc_restore_tokens_buf(RedSocket *sckt, int
> buf->base.base.release_proc = restore_tokens_buf_release;
> buf->num_tokens = num_tokens;
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL DBG: num_tokens=%d", num_tokens);
> + red_log(2, "TUNNEL DBG: num_tokens=%d", num_tokens);
> #endif
> return &buf->base.base;
> }
> @@ -2055,7 +2056,8 @@ static void tunnel_channel_restore_migrated_socket(TunnelChannel *channel,
> static void tunnel_channel_restore_socket_state(TunnelChannel *channel, RedSocket *sckt)
> {
> int ret = TRUE;
> - red_printf("");
> +
> + red_log(2, "");
> // handling client status msgs that were received during migration
> switch (sckt->mig_client_status_msg) {
> case 0:
> @@ -2162,14 +2164,14 @@ static int tunnel_channel_handle_migrate_data(TunnelChannel *channel,
> int i;
>
> if (!channel->expect_migrate_data) {
> - red_printf("unexpected");
> + red_warn("unexpected");
> goto error;
> }
> channel->expect_migrate_data = FALSE;
>
> if (migrate_data->magic != TUNNEL_MIGRATE_DATA_MAGIC ||
> migrate_data->version != TUNNEL_MIGRATE_DATA_VERSION) {
> - red_printf("invalid content");
> + red_warn("invalid content");
> goto error;
> }
>
> @@ -2186,7 +2188,7 @@ static int tunnel_channel_handle_migrate_data(TunnelChannel *channel,
> services_list->services[i]),
> migrate_data->data);
> if (CHECK_TUNNEL_ERROR(channel)) {
> - red_printf("failed restoring service");
> + red_warn("failed restoring service");
> goto error;
> }
> }
> @@ -2199,7 +2201,7 @@ static int tunnel_channel_handle_migrate_data(TunnelChannel *channel,
> sockets_list->sockets[i]),
> migrate_data->data);
> if (CHECK_TUNNEL_ERROR(channel)) {
> - red_printf("failed restoring socket");
> + red_warn("failed restoring socket");
> goto error;
> }
> }
> @@ -2242,7 +2244,7 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
> // the first field in these messages is connection id
> sckt = tunnel_channel->worker->sockets + (*((uint16_t *)msg));
> if (!sckt->allocated) {
> - red_printf("red socket not found");
> + red_warn("red socket not found");
> return FALSE;
> }
> break;
> @@ -2253,18 +2255,18 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
> switch (header->type) {
> case SPICE_MSGC_TUNNEL_SERVICE_ADD:
> if (header->size < sizeof(SpiceMsgcTunnelAddGenericService)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> free(msg);
> return FALSE;
> }
> return tunnel_channel_handle_service_add(tunnel_channel,
> (SpiceMsgcTunnelAddGenericService *)msg);
> case SPICE_MSGC_TUNNEL_SERVICE_REMOVE:
> - red_printf("REDC_TUNNEL_REMOVE_SERVICE not supported yet");
> + red_warn("REDC_TUNNEL_REMOVE_SERVICE not supported yet");
> return FALSE;
> case SPICE_MSGC_TUNNEL_SOCKET_OPEN_ACK:
> if (header->size != sizeof(SpiceMsgcTunnelSocketOpenAck)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
>
> @@ -2273,7 +2275,7 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
>
> case SPICE_MSGC_TUNNEL_SOCKET_OPEN_NACK:
> if (header->size != sizeof(SpiceMsgcTunnelSocketOpenNack)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
>
> @@ -2281,7 +2283,7 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
> case SPICE_MSGC_TUNNEL_SOCKET_DATA:
> {
> if (header->size < sizeof(SpiceMsgcTunnelSocketData)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
>
> @@ -2291,25 +2293,25 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
> }
> case SPICE_MSGC_TUNNEL_SOCKET_FIN:
> if (header->size != sizeof(SpiceMsgcTunnelSocketFin)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
> return tunnel_channel_handle_socket_fin(tunnel_channel, sckt);
> case SPICE_MSGC_TUNNEL_SOCKET_CLOSED:
> if (header->size != sizeof(SpiceMsgcTunnelSocketClosed)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
> return tunnel_channel_handle_socket_closed(tunnel_channel, sckt);
> case SPICE_MSGC_TUNNEL_SOCKET_CLOSED_ACK:
> if (header->size != sizeof(SpiceMsgcTunnelSocketClosedAck)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
> return tunnel_channel_handle_socket_closed_ack(tunnel_channel, sckt);
> case SPICE_MSGC_TUNNEL_SOCKET_TOKEN:
> if (header->size != sizeof(SpiceMsgcTunnelSocketTokens)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
>
> @@ -2319,7 +2321,7 @@ static int tunnel_channel_handle_message(RedChannel *channel, SpiceDataHeader *h
> return tunnel_channel_handle_migrate_mark(tunnel_channel);
> case SPICE_MSGC_MIGRATE_DATA:
> if (header->size < sizeof(TunnelMigrateData)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> free(msg);
> return FALSE;
> }
> @@ -2594,9 +2596,9 @@ static void tunnel_channel_send_socket_fin(TunnelChannel *channel, PipeItem *ite
> ASSERT(!sckt->out_data.ready_chunks_queue.head);
>
> if (sckt->out_data.process_queue->head) {
> - red_printf("socket sent FIN but there are still buffers in outgoing process queue"
> - "(local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port), sckt->far_service->id);
> + red_warn("socket sent FIN but there are still buffers in outgoing process queue"
> + "(local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port), sckt->far_service->id);
> }
>
> channel->send_data.u.socket_fin.connection_id = sckt->connection_id;
> @@ -2619,16 +2621,16 @@ static void tunnel_channel_send_socket_close(TunnelChannel *channel, PipeItem *i
>
> // can happen when it is a forced close
> if (sckt->out_data.ready_chunks_queue.head) {
> - red_printf("socket closed but there are still buffers in outgoing ready queue"
> - "(local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port),
> - sckt->far_service->id);
> + red_warn("socket closed but there are still buffers in outgoing ready queue"
> + "(local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port),
> + sckt->far_service->id);
> }
>
> if (sckt->out_data.process_queue->head) {
> - red_printf("socket closed but there are still buffers in outgoing process queue"
> - "(local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port), sckt->far_service->id);
> + red_warn("socket closed but there are still buffers in outgoing process queue"
> + "(local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port), sckt->far_service->id);
> }
>
> channel->send_data.u.socket_close.connection_id = sckt->connection_id;
> @@ -2924,7 +2926,7 @@ static int tunnel_socket_connect(SlirpUsrNetworkInterface *usr_interface,
> ASSERT(usr_interface);
>
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL_DBG");
> + red_log(2, "TUNNEL_DBG");
> #endif
> worker = ((RedSlirpNetworkInterface *)usr_interface)->worker;
> ASSERT(worker->channel);
> @@ -2938,13 +2940,13 @@ static int tunnel_socket_connect(SlirpUsrNetworkInterface *usr_interface,
> }
>
> if (tunnel_worker_find_socket(worker, src_port, far_service->id)) {
> - red_printf("slirp tried to open a socket that is still opened");
> + red_warn("slirp tried to open a socket that is still opened");
> errno = EADDRINUSE;
> return -1;
> }
>
> if (worker->num_sockets == MAX_SOCKETS_NUM) {
> - red_printf("number of tunneled sockets exceeds the limit");
> + red_warn("number of tunneled sockets exceeds the limit");
> errno = ENFILE;
> return -1;
> }
> @@ -2992,7 +2994,7 @@ static int tunnel_socket_send(SlirpUsrNetworkInterface *usr_interface, UserSocke
>
> if ((sckt->client_status != CLIENT_SCKT_STATUS_OPEN) &&
> (sckt->client_status != CLIENT_SCKT_STATUS_SHUTDOWN_SEND)) {
> - red_printf("client socket is unable to receive data");
> + red_warn("client socket is unable to receive data");
> errno = ECONNRESET;
> return -1;
> }
> @@ -3000,7 +3002,7 @@ static int tunnel_socket_send(SlirpUsrNetworkInterface *usr_interface, UserSocke
>
> if ((sckt->slirp_status == SLIRP_SCKT_STATUS_SHUTDOWN_SEND) ||
> (sckt->slirp_status == SLIRP_SCKT_STATUS_WAIT_CLOSE)) {
> - red_printf("send was shutdown");
> + red_warn("send was shutdown");
> errno = EPIPE;
> return -1;
> }
> @@ -3026,9 +3028,9 @@ static int tunnel_socket_send(SlirpUsrNetworkInterface *usr_interface, UserSocke
> ASSERT(sckt->out_data.process_queue->head);
> if ((sckt->out_data.data_size + len) >
> (MAX_SOCKET_OUT_BUFFERS * MAX_SOCKET_DATA_SIZE)) {
> - red_printf("socket out buffers overflow, socket will be closed"
> - " (local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port), sckt->far_service->id);
> + red_warn("socket out buffers overflow, socket will be closed"
> + " (local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port), sckt->far_service->id);
> tunnel_socket_force_close(worker->channel, sckt);
> size_to_send = 0;
> } else {
> @@ -3118,9 +3120,9 @@ static int tunnel_socket_recv(SlirpUsrNetworkInterface *usr_interface, UserSocke
> // if there is data in ready queue, when it is acked, slirp will call recv and get 0
> if (__should_send_fin_to_guest(sckt)) {
> if (sckt->in_data.process_queue->head) {
> - red_printf("client socket sent FIN but there are still buffers in incoming process"
> - "queue (local_port=%d, service_id=%d)",
> - ntohs(sckt->local_port), sckt->far_service->id);
> + red_warn("client socket sent FIN but there are still buffers in incoming process"
> + "queue (local_port=%d, service_id=%d)",
> + ntohs(sckt->local_port), sckt->far_service->id);
> }
> return 0; // slirp will call shutdown recv now and it will also send FIN to the guest.
> }
> @@ -3326,7 +3328,7 @@ static void arm_timer(SlirpUsrNetworkInterface *usr_interface, UserTimer *timer,
> worker = ((RedSlirpNetworkInterface *)usr_interface)->worker;
> #ifdef DEBUG_NETWORK
> if (!worker->channel) {
> - red_printf("channel not connected");
> + red_warn("channel not connected");
> }
> #endif
> if (worker->channel && worker->channel->mig_inprogress) {
> @@ -3348,12 +3350,12 @@ static int tunnel_channel_config_socket(RedChannel *channel)
> int delay_val;
>
> if ((flags = fcntl(channel->stream->socket, F_GETFL)) == -1) {
> - red_printf("accept failed, %s", strerror(errno)); // can't we just use red_error?
> + red_warn("accept failed, %s", strerror(errno)); // can't we just use red_error?
> return FALSE;
> }
>
> if (fcntl(channel->stream->socket, F_SETFL, flags | O_NONBLOCK) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> return FALSE;
> }
>
> @@ -3361,7 +3363,7 @@ static int tunnel_channel_config_socket(RedChannel *channel)
>
> if (setsockopt(channel->stream->socket, IPPROTO_TCP, TCP_NODELAY, &delay_val,
> sizeof(delay_val)) == -1) {
> - red_printf("setsockopt failed, %s", strerror(errno));
> + red_warn("setsockopt failed, %s", strerror(errno));
> }
>
> return TRUE;
> @@ -3396,7 +3398,7 @@ static void tunnel_channel_disconnect(RedChannel *channel)
> if (!channel) {
> return;
> }
> - red_printf("");
> + red_log(2, "");
> worker = tunnel_channel->worker;
>
> tunnel_worker_disconnect_slirp(worker);
> @@ -3461,7 +3463,7 @@ static void handle_tunnel_channel_shutdown(struct Channel *channel)
> static void handle_tunnel_channel_migrate(struct Channel *channel)
> {
> #ifdef DEBUG_NETWORK
> - red_printf("TUNNEL_DBG: MIGRATE STARTED");
> + red_log(2, "TUNNEL_DBG: MIGRATE STARTED");
> #endif
> TunnelChannel *tunnel_channel = ((TunnelWorker *)channel->data)->channel;
> tunnel_channel->mig_inprogress = TRUE;
> diff --git a/server/red_worker.c b/server/red_worker.c
> index 5f07803..0d67586 100644
> --- a/server/red_worker.c
> +++ b/server/red_worker.c
> @@ -995,46 +995,46 @@ static void print_compress_stats(DisplayChannel *display_channel)
> display_channel->zlib_glz_stat.comp_size :
> display_channel->glz_stat.comp_size;
>
> - red_printf("==> Compression stats for display %u", display_channel->base.id);
> - red_printf("Method \t count \torig_size(MB)\tenc_size(MB)\tenc_time(s)");
> - red_printf("QUIC \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "==> Compression stats for display %u", display_channel->base.id);
> + red_log(2, "Method \t count \torig_size(MB)\tenc_size(MB)\tenc_time(s)");
> + red_log(2, "QUIC \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->quic_stat.count,
> stat_byte_to_mega(display_channel->quic_stat.orig_size),
> stat_byte_to_mega(display_channel->quic_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->quic_stat.total)
> );
> - red_printf("GLZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "GLZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->glz_stat.count,
> stat_byte_to_mega(display_channel->glz_stat.orig_size),
> stat_byte_to_mega(display_channel->glz_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->glz_stat.total)
> );
> - red_printf("ZLIB GLZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "ZLIB GLZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->zlib_glz_stat.count,
> stat_byte_to_mega(display_channel->zlib_glz_stat.orig_size),
> stat_byte_to_mega(display_channel->zlib_glz_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->zlib_glz_stat.total)
> );
> - red_printf("LZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "LZ \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->lz_stat.count,
> stat_byte_to_mega(display_channel->lz_stat.orig_size),
> stat_byte_to_mega(display_channel->lz_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->lz_stat.total)
> );
> - red_printf("JPEG \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "JPEG \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->jpeg_stat.count,
> stat_byte_to_mega(display_channel->jpeg_stat.orig_size),
> stat_byte_to_mega(display_channel->jpeg_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->jpeg_stat.total)
> );
> - red_printf("JPEG-RGBA\t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "JPEG-RGBA\t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->jpeg_alpha_stat.count,
> stat_byte_to_mega(display_channel->jpeg_alpha_stat.orig_size),
> stat_byte_to_mega(display_channel->jpeg_alpha_stat.comp_size),
> stat_cpu_time_to_sec(display_channel->jpeg_alpha_stat.total)
> );
> - red_printf("-------------------------------------------------------------------");
> - red_printf("Total \t%8d\t%13.2f\t%12.2f\t%12.2f",
> + red_log(2, "-------------------------------------------------------------------");
> + red_log(2, "Total \t%8d\t%13.2f\t%12.2f\t%12.2f",
> display_channel->lz_stat.count + display_channel->glz_stat.count +
> display_channel->quic_stat.count +
> display_channel->jpeg_stat.count +
> @@ -1917,7 +1917,7 @@ void __show_current(TreeItem *item, void *data)
> static void show_current(RedWorker *worker, Ring *ring)
> {
> if (ring_is_empty(ring)) {
> - red_printf("TEST: TREE: EMPTY");
> + red_log(2, "TEST: TREE: EMPTY");
> return;
> }
> current_tree_for_each(worker, ring, __show_current, NULL);
> @@ -2918,7 +2918,7 @@ static void red_reset_stream_trace(RedWorker *worker)
> if (!stream->current) {
> red_stop_stream(worker, stream);
> } else {
> - red_printf("attached stream");
> + red_log(2, "attached stream");
> }
> }
>
> @@ -3010,7 +3010,7 @@ static inline int red_current_add(RedWorker *worker, Ring *ring, Drawable *drawa
> if (!((DrawItem *)sibling)->container_root) {
> container = __new_container(worker, (DrawItem *)sibling);
> if (!container) {
> - red_printf("create new container failed");
> + red_warn("create new container failed");
> region_destroy(&exclude_rgn);
> return FALSE;
> }
> @@ -3174,17 +3174,17 @@ static inline int red_current_add_qxl(RedWorker *worker, Ring *ring, Drawable *d
> #ifdef RED_WORKER_STAT
> if ((++worker->add_count % 100) == 0) {
> stat_time_t total = worker->add_stat.total;
> - red_printf("add with shadow count %u",
> + red_log(2, "add with shadow count %u",
> worker->add_with_shadow_count);
> worker->add_with_shadow_count = 0;
> - red_printf("add[%u] %f exclude[%u] %f __exclude[%u] %f",
> + red_log(2, "add[%u] %f exclude[%u] %f __exclude[%u] %f",
> worker->add_stat.count,
> stat_cpu_time_to_sec(total),
> worker->exclude_stat.count,
> stat_cpu_time_to_sec(worker->exclude_stat.total),
> worker->__exclude_stat.count,
> stat_cpu_time_to_sec(worker->__exclude_stat.total));
> - red_printf("add %f%% exclude %f%% exclude2 %f%% __exclude %f%%",
> + red_log(2, "add %f%% exclude %f%% exclude2 %f%% __exclude %f%%",
> (double)(total - worker->exclude_stat.total) / total * 100,
> (double)(worker->exclude_stat.total) / total * 100,
> (double)(worker->exclude_stat.total -
> @@ -3902,7 +3902,7 @@ static void red_draw_qxl_drawable(RedWorker *worker, Drawable *drawable)
> break;
> }
> default:
> - red_printf("invalid type");
> + red_warn("invalid type");
> }
> }
>
> @@ -4396,7 +4396,7 @@ static int red_process_commands(RedWorker *worker, uint32_t max_pipe_size, int *
> &message, ext_cmd.cmd.data);
> #ifdef DEBUG
> /* alert: accessing message.data is insecure */
> - red_printf("MESSAGE: %s", message.data);
> + red_log(2, "MESSAGE: %s", message.data);
> #endif
> release_info_ext.group_id = ext_cmd.group_id;
> release_info_ext.info = message.release_info;
> @@ -4857,7 +4857,7 @@ static void quic_usr_error(QuicUsrContext *usr, const char *fmt, ...)
> va_start(ap, fmt);
> vsnprintf(usr_data->message_buf, sizeof(usr_data->message_buf), fmt, ap);
> va_end(ap);
> - red_printf("%s", usr_data->message_buf);
> + red_warn("%s", usr_data->message_buf);
>
> longjmp(usr_data->jmp_env, 1);
> }
> @@ -4870,7 +4870,7 @@ static void lz_usr_error(LzUsrContext *usr, const char *fmt, ...)
> va_start(ap, fmt);
> vsnprintf(usr_data->message_buf, sizeof(usr_data->message_buf), fmt, ap);
> va_end(ap);
> - red_printf("%s", usr_data->message_buf);
> + red_warn("%s", usr_data->message_buf);
>
> longjmp(usr_data->jmp_env, 1);
> }
> @@ -4898,7 +4898,7 @@ static void quic_usr_warn(QuicUsrContext *usr, const char *fmt, ...)
> va_start(ap, fmt);
> vsnprintf(usr_data->message_buf, sizeof(usr_data->message_buf), fmt, ap);
> va_end(ap);
> - red_printf("%s", usr_data->message_buf);
> + red_warn("%s", usr_data->message_buf);
> }
>
> static void lz_usr_warn(LzUsrContext *usr, const char *fmt, ...)
> @@ -4909,7 +4909,7 @@ static void lz_usr_warn(LzUsrContext *usr, const char *fmt, ...)
> va_start(ap, fmt);
> vsnprintf(usr_data->message_buf, sizeof(usr_data->message_buf), fmt, ap);
> va_end(ap);
> - red_printf("%s", usr_data->message_buf);
> + red_warn("%s", usr_data->message_buf);
> }
>
> static void glz_usr_warn(GlzEncoderUsrContext *usr, const char *fmt, ...)
> @@ -4920,7 +4920,7 @@ static void glz_usr_warn(GlzEncoderUsrContext *usr, const char *fmt, ...)
> va_start(ap, fmt);
> vsnprintf(usr_data->message_buf, sizeof(usr_data->message_buf), fmt, ap);
> va_end(ap);
> - red_printf("%s", usr_data->message_buf);
> + red_warn("%s", usr_data->message_buf);
> }
>
> static void *quic_usr_malloc(QuicUsrContext *usr, int size)
> @@ -5362,7 +5362,7 @@ static inline int red_glz_compress_image(DisplayChannel *display_channel,
> zlib_data->data.bufs_head = zlib_data->data.bufs_tail;
>
> if (!zlib_data->data.bufs_head) {
> - red_printf("failed to allocate zlib compress buffer");
> + red_warn("failed to allocate zlib compress buffer");
> goto glz;
> }
>
> @@ -5523,7 +5523,7 @@ static int red_jpeg_compress_image(DisplayChannel *display_channel, SpiceImage *
> jpeg_data->data.bufs_head = jpeg_data->data.bufs_tail;
>
> if (!jpeg_data->data.bufs_head) {
> - red_printf("failed to allocate compress buffer");
> + red_warn("failed to allocate compress buffer");
> return FALSE;
> }
>
> @@ -5762,7 +5762,7 @@ static inline int red_compress_image(DisplayChannel *display_channel,
>
> if (quic_compress) {
> #ifdef COMPRESS_DEBUG
> - red_printf("QUIC compress");
> + red_log(2, "QUIC compress");
> #endif
> // if bitmaps is picture-like, compress it using jpeg
> if (can_lossy && display_channel->enable_jpeg &&
> @@ -5808,12 +5808,12 @@ static inline int red_compress_image(DisplayChannel *display_channel,
> ret = red_lz_compress_image(display_channel, dest, src, o_comp_data,
> drawable->group_id);
> #ifdef COMPRESS_DEBUG
> - red_printf("LZ LOCAL compress");
> + red_log(2, "LZ LOCAL compress");
> #endif
> }
> #ifdef COMPRESS_DEBUG
> else {
> - red_printf("LZ global compress fmt=%d", src->format);
> + red_log(2, "LZ global compress fmt=%d", src->format);
> }
> #endif
> return ret;
> @@ -7345,7 +7345,7 @@ static void red_send_data(RedChannel *channel, void *item)
> channel->disconnect(channel);
> return;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> channel->disconnect(channel);
> return;
> }
> @@ -7476,7 +7476,7 @@ static inline uint8_t *red_get_image_line(RedWorker *worker, SpiceChunks *chunks
> }
>
> if (chunk->len - *offset < stride) {
> - red_printf("bad chunk alignment");
> + red_warn("bad chunk alignment");
> return NULL;
> }
> ret = chunk->data + *offset;
> @@ -7687,7 +7687,7 @@ static inline int red_send_stream_data(DisplayChannel *display_channel, Drawable
> }
> break;
> default:
> - red_printf_some(1000, "unsupported format %d", image->u.bitmap.format);
> + red_log_some(LOG_WARN, 1000, "unsupported format %d", image->u.bitmap.format);
> return FALSE;
> }
>
> @@ -8307,7 +8307,7 @@ static void display_channel_push(RedWorker *worker)
> free(pipe_item);
> break;
> case PIPE_ITEM_TYPE_MIGRATE:
> - red_printf("PIPE_ITEM_TYPE_MIGRATE");
> + red_log(2, "PIPE_ITEM_TYPE_MIGRATE");
> display_channel_send_migrate(display_channel);
> free(pipe_item);
> break;
> @@ -8379,7 +8379,7 @@ static void cursor_channel_push(RedWorker *worker)
> free(pipe_item);
> break;
> case PIPE_ITEM_TYPE_MIGRATE:
> - red_printf("PIPE_ITEM_TYPE_MIGRATE");
> + red_log(2, "PIPE_ITEM_TYPE_MIGRATE");
> cursor_channel_send_migrate(cursor_channel);
> free(pipe_item);
> break;
> @@ -8762,7 +8762,7 @@ static inline void flush_display_commands(RedWorker *worker)
> red_receive(channel);
> red_send_data(channel, NULL);
> if (red_now() >= end_time) {
> - red_printf("update timeout");
> + red_warn("update timeout");
> red_disconnect_display(channel);
> } else {
> sleep_count++;
> @@ -8804,7 +8804,7 @@ static inline void flush_cursor_commands(RedWorker *worker)
> red_receive(channel);
> red_send_data(channel, NULL);
> if (red_now() >= end_time) {
> - red_printf("flush cursor timeout");
> + red_warn("flush cursor timeout");
> red_disconnect_cursor(channel);
> } else {
> sleep_count++;
> @@ -8854,7 +8854,7 @@ static int display_channel_wait_for_init(DisplayChannel *display_channel)
> return TRUE;
> }
> if (red_now() > end_time) {
> - red_printf("timeout");
> + red_warn("timeout");
> red_disconnect_display((RedChannel *)display_channel);
> break;
> }
> @@ -8904,7 +8904,7 @@ static int channel_handle_message(RedChannel *channel, size_t size, uint32_t typ
> case SPICE_MSGC_DISCONNECTING:
> break;
> default:
> - red_printf("invalid message type %u", type);
> + red_warn("invalid message type %u", type);
> return FALSE;
> }
> return TRUE;
> @@ -8948,7 +8948,7 @@ static GlzSharedDictionary *red_create_glz_dictionary(DisplayChannel *display,
> MAX_LZ_ENCODERS,
> &display->glz_data.usr);
> #ifdef COMPRESS_DEBUG
> - red_printf("Lz Window %d Size=%d", id, window_size);
> + red_log(2, "Lz Window %d Size=%d", id, window_size);
> #endif
> if (!glz_dict) {
> PANIC("failed creating lz dictionary");
> @@ -9136,7 +9136,7 @@ static int display_channel_handle_migrate_glz_dictionary(DisplayChannel *channel
> static int display_channel_handle_migrate_mark(DisplayChannel *channel)
> {
> if (!channel->expect_migrate_mark) {
> - red_printf("unexpected");
> + red_warn("unexpected");
> return FALSE;
> }
> channel->expect_migrate_mark = FALSE;
> @@ -9150,18 +9150,18 @@ static int display_channel_handle_migrate_data(DisplayChannel *channel, size_t s
> int i;
>
> if (!channel->expect_migrate_data) {
> - red_printf("unexpected");
> + red_warn("unexpected");
> return FALSE;
> }
> channel->expect_migrate_data = FALSE;
> if (size < sizeof(*migrate_data)) {
> - red_printf("bad message size");
> + red_warn("bad message size");
> return FALSE;
> }
> migrate_data = (DisplayChannelMigrateData *)message;
> if (migrate_data->magic != DISPLAY_MIGRATE_DATA_MAGIC ||
> migrate_data->version != DISPLAY_MIGRATE_DATA_VERSION) {
> - red_printf("invalid content");
> + red_warn("invalid content");
> return FALSE;
> }
> ASSERT(channel->base.send_data.serial == 0);
> @@ -9202,7 +9202,7 @@ static int display_channel_handle_message(RedChannel *channel, size_t size, uint
> switch (type) {
> case SPICE_MSGC_DISPLAY_INIT:
> if (!((DisplayChannel *)channel)->expect_init) {
> - red_printf("unexpected SPICE_MSGC_DISPLAY_INIT");
> + red_warn("unexpected SPICE_MSGC_DISPLAY_INIT");
> return FALSE;
> }
> ((DisplayChannel *)channel)->expect_init = FALSE;
> @@ -9239,7 +9239,7 @@ static void red_receive(RedChannel *channel)
> channel->disconnect(channel);
> return;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> channel->disconnect(channel);
> return;
> }
> @@ -9261,7 +9261,7 @@ static void red_receive(RedChannel *channel)
> SPICE_VERSION_MINOR, &parsed_size, &parsed_free);
>
> if (parsed == NULL) {
> - red_printf("failed to parse message type %d", header->type);
> + red_warn("failed to parse message type %d", header->type);
> channel->disconnect(channel);
> return;
> }
> @@ -9303,18 +9303,18 @@ static RedChannel *__new_channel(RedWorker *worker, int size, uint32_t channel_i
> int delay_val;
>
> if ((flags = fcntl(stream->socket, F_GETFL)) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> goto error1;
> }
>
> if (fcntl(stream->socket, F_SETFL, flags | O_NONBLOCK) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> goto error1;
> }
>
> delay_val = IS_LOW_BANDWIDTH() ? 0 : 1;
> if (setsockopt(stream->socket, IPPROTO_TCP, TCP_NODELAY, &delay_val, sizeof(delay_val)) == -1) {
> - red_printf("setsockopt failed, %s", strerror(errno));
> + red_warn("setsockopt failed, %s", strerror(errno));
> }
>
> ASSERT(size >= sizeof(*channel));
> @@ -9343,7 +9343,7 @@ static RedChannel *__new_channel(RedWorker *worker, int size, uint32_t channel_i
> event.events = EPOLLIN | EPOLLOUT | EPOLLET;
> event.data.ptr = channel;
> if (epoll_ctl(worker->epoll, EPOLL_CTL_ADD, stream->socket, &event) == -1) {
> - red_printf("epoll_ctl failed, %s", strerror(errno));
> + red_warn("epoll_ctl failed, %s", strerror(errno));
> goto error2;
> }
>
> @@ -9476,8 +9476,8 @@ static void handle_new_display_channel(RedWorker *worker, RedsStream *stream, in
> SPICE_WAN_COMPRESSION_ALWAYS);
> }
>
> - red_printf("jpeg %s", display_channel->enable_jpeg ? "enabled" : "disabled");
> - red_printf("zlib-over-glz %s", display_channel->enable_zlib_glz_wrap ? "enabled" : "disabled");
> + red_log(2, "jpeg %s", display_channel->enable_jpeg ? "enabled" : "disabled");
> + red_log(2, "zlib-over-glz %s", display_channel->enable_zlib_glz_wrap ? "enabled" : "disabled");
>
> // todo: tune level according to bandwidth
> display_channel->zlib_level = ZLIB_DEFAULT_COMPRESSION_LEVEL;
> @@ -9584,7 +9584,7 @@ static void red_wait_outgoing_item(RedChannel *channel)
> red_ref_channel(channel);
>
> end_time = red_now() + DETACH_TIMEOUT;
> - red_printf("blocked");
> + red_log(2, "blocked");
>
> do {
> usleep(DETACH_SLEEP_DURATION);
> @@ -9593,7 +9593,7 @@ static void red_wait_outgoing_item(RedChannel *channel)
> } while ((blocked = channel->send_data.blocked) && red_now() < end_time);
>
> if (blocked) {
> - red_printf("timeout");
> + red_warn("timeout");
> channel->disconnect(channel);
> }
> red_unref_channel(channel);
> @@ -9608,7 +9608,7 @@ static void red_wait_pipe_item_sent(RedChannel *channel, PipeItem *item)
> return;
> }
>
> - red_printf("");
> + red_log(2, "");
> red_ref_channel(channel);
> channel->hold_item(item);
>
> @@ -9629,7 +9629,7 @@ static void red_wait_pipe_item_sent(RedChannel *channel, PipeItem *item)
> }
>
> if (item_in_pipe) {
> - red_printf("timeout");
> + red_warn("timeout");
> channel->disconnect(channel);
> } else {
> if (channel->send_data.item == item) {
> @@ -9991,7 +9991,7 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> display_channel_push(worker);
> }
> if (worker->qxl->st->qif->flush_resources(worker->qxl) == 0) {
> - red_printf("oom current %u pipe %u", worker->current_size, worker->display_channel ?
> + red_warn("oom current %u pipe %u", worker->current_size, worker->display_channel ?
> worker->display_channel->base.pipe_size : 0);
> red_free_some(worker);
> worker->qxl->st->qif->flush_resources(worker->qxl);
> @@ -10023,7 +10023,7 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> case RED_WORKER_MESSAGE_DISPLAY_CONNECT: {
> RedsStream *stream;
> int migrate;
> - red_printf("connect");
> + red_log(2, "connect");
>
> receive_data(worker->channel, &stream, sizeof(RedsStream *));
> receive_data(worker->channel, &migrate, sizeof(int));
> @@ -10031,38 +10031,38 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> break;
> }
> case RED_WORKER_MESSAGE_DISPLAY_DISCONNECT:
> - red_printf("disconnect");
> + red_log(2, "disconnect");
> red_disconnect_display((RedChannel *)worker->display_channel);
> break;
> case RED_WORKER_MESSAGE_STOP: {
> - red_printf("stop");
> + red_log(2, "stop");
> handle_dev_stop(worker);
> break;
> }
> case RED_WORKER_MESSAGE_START:
> - red_printf("start");
> + red_log(2, "start");
> handle_dev_start(worker);
> break;
> case RED_WORKER_MESSAGE_DISPLAY_MIGRATE:
> - red_printf("migrate");
> + red_log(2, "migrate");
> red_migrate_display(worker);
> break;
> case RED_WORKER_MESSAGE_CURSOR_CONNECT: {
> RedsStream *stream;
> int migrate;
>
> - red_printf("cursor connect");
> + red_log(2, "cursor connect");
> receive_data(worker->channel, &stream, sizeof(RedsStream *));
> receive_data(worker->channel, &migrate, sizeof(int));
> red_connect_cursor(worker, stream, migrate);
> break;
> }
> case RED_WORKER_MESSAGE_CURSOR_DISCONNECT:
> - red_printf("cursor disconnect");
> + red_log(2, "cursor disconnect");
> red_disconnect_cursor((RedChannel *)worker->cursor_channel);
> break;
> case RED_WORKER_MESSAGE_CURSOR_MIGRATE:
> - red_printf("cursor migrate");
> + red_log(2, "cursor migrate");
> red_migrate_cursor(worker);
> break;
> case RED_WORKER_MESSAGE_SET_COMPRESSION:
> @@ -10070,25 +10070,25 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> sizeof(spice_image_compression_t));
> switch (worker->image_compression) {
> case SPICE_IMAGE_COMPRESS_AUTO_LZ:
> - red_printf("ic auto_lz");
> + red_log(2, "ic auto_lz");
> break;
> case SPICE_IMAGE_COMPRESS_AUTO_GLZ:
> - red_printf("ic auto_glz");
> + red_log(2, "ic auto_glz");
> break;
> case SPICE_IMAGE_COMPRESS_QUIC:
> - red_printf("ic quic");
> + red_log(2, "ic quic");
> break;
> case SPICE_IMAGE_COMPRESS_LZ:
> - red_printf("ic lz");
> + red_log(2, "ic lz");
> break;
> case SPICE_IMAGE_COMPRESS_GLZ:
> - red_printf("ic glz");
> + red_log(2, "ic glz");
> break;
> case SPICE_IMAGE_COMPRESS_OFF:
> - red_printf("ic off");
> + red_log(2, "ic off");
> break;
> default:
> - red_printf("ic invalid");
> + red_warn("ic invalid");
> }
> #ifdef COMPRESS_STAT
> print_compress_stats(worker->display_channel);
> @@ -10107,21 +10107,21 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> ASSERT(worker->streaming_video != STREAM_VIDEO_INVALID);
> switch(worker->streaming_video) {
> case STREAM_VIDEO_ALL:
> - red_printf("sv all");
> + red_log(2, "sv all");
> break;
> case STREAM_VIDEO_FILTER:
> - red_printf("sv filter");
> + red_log(2, "sv filter");
> break;
> case STREAM_VIDEO_OFF:
> - red_printf("sv off");
> + red_log(2, "sv off");
> break;
> default:
> - red_printf("sv invalid");
> + red_warn("sv invalid");
> }
> break;
> case RED_WORKER_MESSAGE_SET_MOUSE_MODE:
> receive_data(worker->channel, &worker->mouse_mode, sizeof(uint32_t));
> - red_printf("mouse mode %u", worker->mouse_mode);
> + red_log(2, "mouse mode %u", worker->mouse_mode);
> break;
> case RED_WORKER_MESSAGE_ADD_MEMSLOT_ASYNC:
> case RED_WORKER_MESSAGE_ADD_MEMSLOT:
> @@ -10139,7 +10139,7 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> RedCursorCmd *cursor_cmd;
> RedSurfaceCmd *surface_cmd;
>
> - red_printf("loadvm_commands");
> + red_log(2, "loadvm_commands");
> receive_data(worker->channel, &count, sizeof(uint32_t));
> while (count > 0) {
> receive_data(worker->channel, &ext, sizeof(QXLCommandExt));
> @@ -10157,7 +10157,7 @@ static void handle_dev_input(EventListener *listener, uint32_t events)
> red_process_surface(worker, surface_cmd, ext.group_id, TRUE);
> break;
> default:
> - red_printf("unhandled loadvm command type (%d)", ext.cmd.type);
> + red_warn("unhandled loadvm command type (%d)", ext.cmd.type);
> break;
> }
> count--;
> @@ -10251,7 +10251,7 @@ void *red_worker_main(void *arg)
> {
> RedWorker worker;
>
> - red_printf("begin");
> + red_log(2, "begin");
> ASSERT(MAX_PIPE_SIZE > WIDE_CLIENT_ACK_WINDOW &&
> MAX_PIPE_SIZE > NARROW_CLIENT_ACK_WINDOW); //ensure wakeup by ack message
>
> @@ -10316,7 +10316,7 @@ void *red_worker_main(void *arg)
> }
> red_push(&worker);
> }
> - red_printf("exit");
> + red_log(2, "exit");
> return 0;
> }
>
> diff --git a/server/reds.c b/server/reds.c
> index 8e83b99..ed6bd34 100644
> --- a/server/reds.c
> +++ b/server/reds.c
> @@ -637,7 +637,7 @@ void reds_unregister_channel(Channel *channel)
> }
> now = &(*now)->next;
> }
> - red_printf("not found");
> + red_warn("not found");
> }
>
> static Channel *reds_find_channel(uint32_t type, uint32_t id)
> @@ -732,7 +732,7 @@ static void reds_disconnect()
> return;
> }
>
> - red_printf("");
> + red_log(2, "");
> reds->disconnecting = TRUE;
> reds_reset_outgoing();
> /* Reset write filter to start with clean state on client reconnect */
> @@ -801,7 +801,7 @@ static int handle_incoming(RedsStream *stream, IncomingHandler *handler)
> case EPIPE:
> return -1;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> return -1;
> }
> } else {
> @@ -819,7 +819,7 @@ static int handle_incoming(RedsStream *stream, IncomingHandler *handler)
> parsed = handler->parser(data, data + header->size, header->type,
> SPICE_VERSION_MINOR, &parsed_size, &parsed_free);
> if (parsed == NULL) {
> - red_printf("failed to parse message type %d", header->type);
> + red_warn("failed to parse message type %d", header->type);
> return -1;
> }
> handler->handle_message(handler->opaque, parsed_size, header->type, parsed);
> @@ -855,7 +855,7 @@ static int handle_outgoing(RedsStream *stream, OutgoingHandler *handler)
> case EPIPE:
> return -1;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> return -1;
> }
> } else {
> @@ -895,7 +895,7 @@ static int outgoing_write(RedsStream *stream, OutgoingHandler *handler, void *in
> case EPIPE:
> return OUTGOING_FAILED;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> return OUTGOING_FAILED;
> }
> } else {
> @@ -945,7 +945,7 @@ static void reds_send_channels()
> int i;
>
> if (reds->mig_target) {
> - red_printf("warning: unexpected SPICE_MSGC_MAIN_ATTACH_CHANNELS during migration");
> + red_warn("warning: unexpected SPICE_MSGC_MAIN_ATTACH_CHANNELS during migration");
> return;
> }
>
> @@ -996,7 +996,7 @@ static int send_ping(int size)
> static void do_ping_client(const char *opt, int has_interval, int interval)
> {
> if (!reds->stream) {
> - red_printf("not connected to stream");
> + red_warn("not connected to stream");
> return;
> }
>
> @@ -1017,7 +1017,7 @@ static void do_ping_client(const char *opt, int has_interval, int interval)
> static void ping_timer_cb()
> {
> if (!reds->stream) {
> - red_printf("not connected to stream, ping off");
> + red_warn("not connected to stream, ping off");
> core->timer_cancel(reds->ping_timer);
> return;
> }
> @@ -1247,7 +1247,7 @@ static void dispatch_vdi_port_data(int port, VDIReadBuf *buf)
> break;
> default:
> ring_add(&state->read_bufs, &buf->link);
> - red_printf("invalid port");
> + red_warn("invalid port");
> reds_agent_remove();
> }
> }
> @@ -1488,7 +1488,7 @@ static int main_channel_restore_vdi_read_state(MainMigrateData *data, uint8_t **
> switch (state->read_state) {
> case VDI_PORT_READ_STATE_READ_HADER:
> if (data->read_buf_len) {
> - red_printf("unexpected receive buf");
> + red_warn("unexpected receive buf");
> reds_disconnect();
> return FALSE;
> }
> @@ -1496,13 +1496,13 @@ static int main_channel_restore_vdi_read_state(MainMigrateData *data, uint8_t **
> break;
> case VDI_PORT_READ_STATE_GET_BUFF:
> if (state->message_recive_len > state->vdi_chunk_header.size) {
> - red_printf("invalid message receive len");
> + red_warn("invalid message receive len");
> reds_disconnect();
> return FALSE;
> }
>
> if (data->read_buf_len) {
> - red_printf("unexpected receive buf");
> + red_warn("unexpected receive buf");
> reds_disconnect();
> return FALSE;
> }
> @@ -1512,20 +1512,20 @@ static int main_channel_restore_vdi_read_state(MainMigrateData *data, uint8_t **
> uint32_t n;
>
> if (!data->read_buf_len) {
> - red_printf("read state and read_buf_len == 0");
> + red_warn("read state and read_buf_len == 0");
> reds_disconnect();
> return FALSE;
> }
>
> if (state->message_recive_len > state->vdi_chunk_header.size) {
> - red_printf("invalid message receive len");
> + red_warn("invalid message receive len");
> reds_disconnect();
> return FALSE;
> }
>
>
> if (!(ring_item = ring_get_head(&state->read_bufs))) {
> - red_printf("get read buf failed");
> + red_warn("get read buf failed");
> reds_disconnect();
> return FALSE;
> }
> @@ -1535,7 +1535,7 @@ static int main_channel_restore_vdi_read_state(MainMigrateData *data, uint8_t **
> buff->len = data->read_buf_len;
> n = buff->len - state->recive_len;
> if (buff->len > SPICE_AGENT_MAX_DATA_SIZE || n > SPICE_AGENT_MAX_DATA_SIZE) {
> - red_printf("bad read position");
> + red_warn("bad read position");
> reds_disconnect();
> return FALSE;
> }
> @@ -1545,7 +1545,7 @@ static int main_channel_restore_vdi_read_state(MainMigrateData *data, uint8_t **
> break;
> }
> default:
> - red_printf("invalid read state");
> + red_warn("invalid read state");
> reds_disconnect();
> return FALSE;
> }
> @@ -1573,14 +1573,14 @@ static int main_channel_restore_vdi_wqueue(MainMigrateData *data, uint8_t *pos,
> inf_end = inf + data->write_queue_size;
> pos = (uint8_t *)inf_end;
> if (pos > end) {
> - red_printf("access violation");
> + red_warn("access violation");
> reds_disconnect();
> return FALSE;
> }
>
> for (; inf < inf_end; inf++) {
> if (pos + inf->len > end) {
> - red_printf("access violation");
> + red_warn("access violation");
> reds_disconnect();
> return FALSE;
> }
> @@ -1588,7 +1588,7 @@ static int main_channel_restore_vdi_wqueue(MainMigrateData *data, uint8_t *pos,
> VDInternalBuf *buf;
>
> if (inf->len > sizeof(*buf) - SPICE_OFFSETOF(VDInternalBuf, header)) {
> - red_printf("bad buffer len");
> + red_warn("bad buffer len");
> reds_disconnect();
> return FALSE;
> }
> @@ -1604,12 +1604,12 @@ static int main_channel_restore_vdi_wqueue(MainMigrateData *data, uint8_t *pos,
>
> state->num_tokens--;
> if (inf->len > sizeof(*buf) - SPICE_OFFSETOF(VDAgentExtBuf, buf)) {
> - red_printf("bad buffer len");
> + red_warn("bad buffer len");
> reds_disconnect();
> return FALSE;
> }
> if (!(ring_item = ring_get_head(&reds->agent_state.external_bufs))) {
> - red_printf("no external buff");
> + red_warn("no external buff");
> reds_disconnect();
> return FALSE;
> }
> @@ -1620,7 +1620,7 @@ static int main_channel_restore_vdi_wqueue(MainMigrateData *data, uint8_t *pos,
> buf->base.write_len = inf->len;
> ring_add(&reds->agent_state.write_queue, &buf->base.link);
> } else {
> - red_printf("invalid data");
> + red_warn("invalid data");
> reds_disconnect();
> return FALSE;
> }
> @@ -1635,7 +1635,7 @@ static void main_channel_recive_migrate_data(MainMigrateData *data, uint8_t *end
> uint8_t *pos;
>
> if (data->version != MAIN_CHANNEL_MIG_DATA_VERSION) {
> - red_printf("version mismatch");
> + red_warn("version mismatch");
> reds_disconnect();
> return;
> }
> @@ -1684,7 +1684,7 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
>
> switch (type) {
> case SPICE_MSGC_MAIN_AGENT_START:
> - red_printf("agent start");
> + red_log(2, "agent start");
> if (!reds->stream || !vdagent) {
> return;
> }
> @@ -1695,7 +1695,7 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> VDAgentExtBuf *buf;
>
> if (!reds->agent_state.num_client_tokens) {
> - red_printf("token violation");
> + red_warn("token violation");
> reds_disconnect();
> break;
> }
> @@ -1715,7 +1715,7 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> }
>
> if (!(ring_item = ring_get_head(&reds->agent_state.external_bufs))) {
> - red_printf("no agent free bufs");
> + red_warn("no agent free bufs");
> reds_disconnect();
> break;
> }
> @@ -1735,14 +1735,14 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> reds_send_channels();
> break;
> case SPICE_MSGC_MAIN_MIGRATE_CONNECTED:
> - red_printf("client connected to migration target");
> + red_log(2, "client connected to migration target");
> if (reds->mig_wait_connect) {
> reds->mig_connect_ok = TRUE;
> reds_mig_cleanup();
> }
> break;
> case SPICE_MSGC_MAIN_MIGRATE_CONNECT_ERROR:
> - red_printf("mig connect error");
> + red_log(2, "mig connect error");
> if (reds->mig_wait_connect) {
> reds->mig_connect_ok = FALSE;
> reds_mig_cleanup();
> @@ -1754,14 +1754,14 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> if (reds->is_client_mouse_allowed) {
> reds_set_mouse_mode(SPICE_MOUSE_MODE_CLIENT);
> } else {
> - red_printf("client mouse is disabled");
> + red_log(2, "client mouse is disabled");
> }
> break;
> case SPICE_MOUSE_MODE_SERVER:
> reds_set_mouse_mode(SPICE_MOUSE_MODE_SERVER);
> break;
> default:
> - red_printf("unsupported mouse mode");
> + red_warn("unsupported mouse mode");
> }
> break;
> }
> @@ -1789,12 +1789,12 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> if (roundtrip <= latency) {
> // probably high load on client or server result with incorrect values
> latency = 0;
> - red_printf("net test: invalid values, latency %lu roundtrip %lu. assuming high"
> - "bandwidth", latency, roundtrip);
> + red_warn("net test: invalid values, latency %lu roundtrip %lu. assuming high"
> + "bandwidth", latency, roundtrip);
> break;
> }
> bitrate_per_sec = (uint64_t)(NET_TEST_BYTES * 8) * 1000000 / (roundtrip - latency);
> - red_printf("net test: latency %f ms, bitrate %lu bps (%f Mbps)%s",
> + red_log(2, "net test: latency %f ms, bitrate %lu bps (%f Mbps)%s",
> (double)latency / 1000,
> bitrate_per_sec,
> (double)bitrate_per_sec / 1024 / 1024,
> @@ -1802,10 +1802,10 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> reds->net_test_stage = NET_TEST_STAGE_INVALID;
> break;
> default:
> - red_printf("invalid net test stage, ping id %d test id %d stage %d",
> - ping->id,
> - reds->net_test_id,
> - reds->net_test_stage);
> + red_warn("invalid net test stage, ping id %d test id %d stage %d",
> + ping->id,
> + reds->net_test_id,
> + reds->net_test_stage);
> }
> break;
> }
> @@ -1827,18 +1827,18 @@ static void reds_main_handle_message(void *opaque, size_t size, uint32_t type, v
> break;
> case SPICE_MSGC_MAIN_MIGRATE_END:
> if (!reds->mig_target) {
> - red_printf("unexpected SPICE_MSGC_MIGRATE_END, not target");
> + red_warn("unexpected SPICE_MSGC_MIGRATE_END, not target");
> return;
> }
> if (!reds->client_semi_mig_cap) {
> - red_printf("unexpected SPICE_MSGC_MIGRATE_END"
> - ",client does not support semi-seamless migration");
> + red_warn("unexpected SPICE_MSGC_MIGRATE_END"
> + ",client does not support semi-seamless migration");
> return;
> }
> reds_handle_client_migrate_complete();
> break;
> default:
> - red_printf("unexpected type %d", type);
> + red_warn("unexpected type %d", type);
> }
> }
>
> @@ -1865,7 +1865,7 @@ static int reds_send_data()
> reds_disconnect();
> return FALSE;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> reds_disconnect();
> return FALSE;
> }
> @@ -2025,12 +2025,12 @@ static int reds_send_link_ack(RedLinkInfo *link)
> ack.caps_offset = sizeof(SpiceLinkReply);
>
> if (!(link->tiTicketing.rsa = RSA_new())) {
> - red_printf("RSA nes failed");
> + red_warn("RSA nes failed");
> return FALSE;
> }
>
> if (!(bio = BIO_new(BIO_s_mem()))) {
> - red_printf("BIO new failed");
> + red_warn("BIO new failed");
> return FALSE;
> }
>
> @@ -2076,7 +2076,7 @@ static int reds_send_link_error(RedLinkInfo *link, uint32_t error)
>
> static void reds_show_new_channel(RedLinkInfo *link, int connection_id)
> {
> - red_printf("channel %d:%d, connected successfully, over %s link",
> + red_log(2, "channel %d:%d, connected successfully, over %s link",
> link->link_mess->channel_type,
> link->link_mess->channel_id,
> link->stream->ssl == NULL ? "Non Secure" : "Secure");
> @@ -2153,7 +2153,7 @@ static void reds_handle_main_link(RedLinkInfo *link)
> uint32_t *channel_caps;
> uint32_t num_channel_caps;
>
> - red_printf("");
> + red_log(2, "");
>
> reds_disconnect();
>
> @@ -2184,8 +2184,8 @@ static void reds_handle_main_link(RedLinkInfo *link)
> NULL;
> reds->client_semi_mig_cap = test_capability(channel_caps, num_channel_caps, SPICE_MAIN_CAP_SEMI_SEAMLESS_MIGRATE);
> if (reds->client_semi_mig_cap && (SPICE_VERSION_MAJOR == 2) && (reds->peer_minor_version < 1)) {
> - red_printf("warning: client claims to support semi seamless migration,"
> - "but its version is incompatible");
> + red_warn("warning: client claims to support semi seamless migration,"
> + "but its version is incompatible");
> reds->client_semi_mig_cap = FALSE;
> }
>
> @@ -2323,7 +2323,7 @@ static void inputs_handle_input(void *opaque, size_t size, uint32_t type, void *
> if (++state->motion_count % SPICE_INPUT_MOTION_ACK_BUNCH == 0) {
> m = marshaller_new_for_outgoing(state, SPICE_MSG_INPUTS_MOUSE_MOTION_ACK);
> if (!marshaller_outgoing_write(m, state)) {
> - red_printf("motion ack failed");
> + red_warn("motion ack failed");
> reds_disconnect();
> }
> spice_marshaller_destroy(m);
> @@ -2343,7 +2343,7 @@ static void inputs_handle_input(void *opaque, size_t size, uint32_t type, void *
> if (++state->motion_count % SPICE_INPUT_MOTION_ACK_BUNCH == 0) {
> m = marshaller_new_for_outgoing(state, SPICE_MSG_INPUTS_MOUSE_MOTION_ACK);
> if (!marshaller_outgoing_write(m, state)) {
> - red_printf("position ack failed");
> + red_warn("position ack failed");
> reds_disconnect();
> }
> spice_marshaller_destroy(m);
> @@ -2443,7 +2443,7 @@ static void inputs_handle_input(void *opaque, size_t size, uint32_t type, void *
> case SPICE_MSGC_DISCONNECTING:
> break;
> default:
> - red_printf("unexpected type %d", type);
> + red_warn("unexpected type %d", type);
> }
> }
>
> @@ -2517,7 +2517,7 @@ static void inputs_migrate(Channel *channel)
> spice_marshall_msg_migrate(m, &migrate);
>
> if (!marshaller_outgoing_write(m, state)) {
> - red_printf("write failed");
> + red_warn("write failed");
> }
> spice_marshaller_destroy(m);
> }
> @@ -2526,8 +2526,8 @@ static void inputs_select(void *opaque, int select)
> {
> InputsState *inputs_state;
> int eventmask = SPICE_WATCH_EVENT_READ;
> - red_printf("");
>
> + red_log(2, "");
> inputs_state = (InputsState *)opaque;
> if (select) {
> eventmask |= SPICE_WATCH_EVENT_WRITE;
> @@ -2537,7 +2537,7 @@ static void inputs_select(void *opaque, int select)
>
> static void inputs_may_write(void *opaque)
> {
> - red_printf("");
> + red_log(2, "");
> }
>
> static void inputs_link(Channel *channel, RedsStream *stream, int migration,
> @@ -2548,19 +2548,19 @@ static void inputs_link(Channel *channel, RedsStream *stream, int migration,
> int delay_val;
> int flags;
>
> - red_printf("");
> + red_log(2, "");
> ASSERT(channel->data == NULL);
>
> inputs_state = spice_new0(InputsState, 1);
>
> delay_val = 1;
> - if (setsockopt(stream->socket, IPPROTO_TCP, TCP_NODELAY, &delay_val, sizeof(delay_val)) == -1) {
> - red_printf("setsockopt failed, %s", strerror(errno));
> + if (setsockopt(stream->socket, IPPROTO_TCP,TCP_NODELAY, &delay_val, sizeof(delay_val)) == -1) {
> + red_warn("setsockopt failed, %s", strerror(errno));
> }
>
> if ((flags = fcntl(stream->socket, F_GETFL)) == -1 ||
> fcntl(stream->socket, F_SETFL, flags | O_ASYNC) == -1) {
> - red_printf("fcntl failed, %s", strerror(errno));
> + red_warn("fcntl failed, %s", strerror(errno));
> }
>
> inputs_state->stream = stream;
> @@ -2584,7 +2584,7 @@ static void inputs_link(Channel *channel, RedsStream *stream, int migration,
> inputs_init.keyboard_modifiers = kbd_get_leds(keyboard);
> spice_marshall_msg_inputs_init(m, &inputs_init);
> if (!marshaller_outgoing_write(m, inputs_state)) {
> - red_printf("failed to send modifiers state");
> + red_warn("failed to send modifiers state");
> reds_disconnect();
> }
> spice_marshaller_destroy(m);
> @@ -2608,7 +2608,7 @@ static void reds_send_keyboard_modifiers(uint8_t modifiers)
> spice_marshall_msg_inputs_key_modifiers(m, &key_modifiers);
>
> if (!marshaller_outgoing_write(m, state)) {
> - red_printf("failed to send modifiers state");
> + red_warn("failed to send modifiers state");
> reds_disconnect();
> }
> spice_marshaller_destroy(m);
> @@ -2665,7 +2665,7 @@ static void reds_mig_pending_link_add(SpiceLinkMess *link_msg, RedsStream *strea
>
> static void reds_mig_pending_links_free(void)
> {
> - red_printf("");
> + red_log(2, "");
> while(reds->mig_pending_links) {
> RedsMigPendingLink *tmp = reds->mig_pending_links;
> reds->mig_pending_links = tmp->next;
> @@ -2717,7 +2717,7 @@ static void reds_handle_client_migrate_complete(void)
> {
> RedsMigPendingLink *cur_link;
>
> - red_printf("");
> + red_log(2, "");
> // TODO: not doing net test. consider doing it on client_migrate_info
> reds_main_channel_init(FALSE);
>
> @@ -2725,8 +2725,8 @@ static void reds_handle_client_migrate_complete(void)
> Channel *channel = reds_find_channel(cur_link->link_msg->channel_type,
> cur_link->link_msg->channel_id);
> if (!channel) {
> - red_printf("warning: channel (%d, %d) (type,id) wasn't found",
> - cur_link->link_msg->channel_type, cur_link->link_msg->channel_id);
> + red_warn("warning: channel (%d, %d) (type,id) wasn't found",
> + cur_link->link_msg->channel_type, cur_link->link_msg->channel_id);
> continue;
> }
> reds_channel_do_link(channel, cur_link->link_msg, cur_link->stream);
> @@ -2804,8 +2804,8 @@ static void reds_handle_ticket(void *opaque)
>
> if (strlen(taTicket.password) == 0) {
> reds_send_link_result(link, SPICE_LINK_ERR_PERMISSION_DENIED);
> - red_printf("Ticketing is enabled, but no password is set. "
> - "please set a ticket first");
> + red_warn("Ticketing is enabled, but no password is set. "
> + "please set a ticket first");
> reds_link_free(link);
> return;
> }
> @@ -2849,7 +2849,7 @@ ssize_t reds_stream_sasl_write(RedsStream *s, const void *buf, size_t nbyte)
> (const char **)&s->sasl.encoded,
> &s->sasl.encodedLength);
> if (err != SASL_OK) {
> - red_printf("sasl_encode error: %d", err);
> + red_warn("sasl_encode error: %d", err);
> return -1;
> }
>
> @@ -2858,7 +2858,7 @@ ssize_t reds_stream_sasl_write(RedsStream *s, const void *buf, size_t nbyte)
> }
>
> if (!s->sasl.encoded) {
> - red_printf("sasl_encode didn't return a buffer!");
> + red_warn("sasl_encode didn't return a buffer!");
> return 0;
> }
>
> @@ -2910,7 +2910,7 @@ static ssize_t reds_stream_sasl_read(RedsStream *s, void *buf, size_t nbyte)
> (char *)encoded, n,
> &decoded, &decodedlen);
> if (err != SASL_OK) {
> - red_printf("sasl_decode error: %d", err);
> + red_warn("sasl_decode error: %d", err);
> return -1;
> }
>
> @@ -2992,8 +2992,8 @@ static char *addr_to_string(const char *format,
> host, sizeof(host),
> serv, sizeof(serv),
> NI_NUMERICHOST | NI_NUMERICSERV)) != 0) {
> - red_printf("Cannot resolve address %d: %s",
> - err, gai_strerror(err));
> + red_warn("Cannot resolve address %d: %s",
> + err, gai_strerror(err));
> return NULL;
> }
>
> @@ -3023,7 +3023,7 @@ static int auth_sasl_check_ssf(RedsSASL *sasl, int *runSSF)
> }
>
> ssf = *(const int *)val;
> - red_printf("negotiated an SSF of %d", ssf);
> + red_log(2, "negotiated an SSF of %d", ssf);
> if (ssf < 56) {
> return 0; /* 56 is good for Kerberos */
> }
> @@ -3070,7 +3070,7 @@ static void reds_handle_auth_sasl_step(void *opaque)
> datalen--; /* Don't count NULL byte when passing to _start() */
> }
>
> - red_printf("Step using SASL Data %p (%d bytes)",
> + red_log(2, "Step using SASL Data %p (%d bytes)",
> clientdata, datalen);
> err = sasl_server_step(sasl->conn,
> clientdata,
> @@ -3079,18 +3079,18 @@ static void reds_handle_auth_sasl_step(void *opaque)
> &serveroutlen);
> if (err != SASL_OK &&
> err != SASL_CONTINUE) {
> - red_printf("sasl step failed %d (%s)",
> - err, sasl_errdetail(sasl->conn));
> + red_warn("sasl step failed %d (%s)",
> + err, sasl_errdetail(sasl->conn));
> goto authabort;
> }
>
> if (serveroutlen > SASL_DATA_MAX_LEN) {
> - red_printf("sasl step reply data too long %d",
> - serveroutlen);
> + red_warn("sasl step reply data too long %d",
> + serveroutlen);
> goto authabort;
> }
>
> - red_printf("SASL return data %d bytes, %p", serveroutlen, serverout);
> + red_log(2, "SASL return data %d bytes, %p", serveroutlen, serverout);
>
> if (serveroutlen) {
> serveroutlen += 1;
> @@ -3104,7 +3104,7 @@ static void reds_handle_auth_sasl_step(void *opaque)
> sync_write_u8(link->stream, err == SASL_CONTINUE ? 0 : 1);
>
> if (err == SASL_CONTINUE) {
> - red_printf("%s", "Authentication must continue (step)");
> + red_log(2, "%s", "Authentication must continue (step)");
> /* Wait for step length */
> obj->now = (uint8_t *)&sasl->len;
> obj->end = obj->now + sizeof(uint32_t);
> @@ -3114,11 +3114,11 @@ static void reds_handle_auth_sasl_step(void *opaque)
> int ssf;
>
> if (auth_sasl_check_ssf(sasl, &ssf) == 0) {
> - red_printf("Authentication rejected for weak SSF");
> + red_warn("Authentication rejected for weak SSF");
> goto authreject;
> }
>
> - red_printf("Authentication successful");
> + red_log(2, "Authentication successful");
> sync_write_u32(link->stream, SPICE_LINK_ERR_OK); /* Accept auth */
>
> /*
> @@ -3148,9 +3148,9 @@ static void reds_handle_auth_sasl_steplen(void *opaque)
> AsyncRead *obj = &link->asyc_read;
> RedsSASL *sasl = &link->stream->sasl;
>
> - red_printf("Got steplen %d", sasl->len);
> + red_log(2, "Got steplen %d", sasl->len);
> if (sasl->len > SASL_DATA_MAX_LEN) {
> - red_printf("Too much SASL data %d", sasl->len);
> + red_warn("Too much SASL data %d", sasl->len);
> reds_link_free(link);
> return;
> }
> @@ -3200,7 +3200,7 @@ static void reds_handle_auth_sasl_start(void *opaque)
> datalen--; /* Don't count NULL byte when passing to _start() */
> }
>
> - red_printf("Start SASL auth with mechanism %s. Data %p (%d bytes)",
> + red_log(2, "Start SASL auth with mechanism %s. Data %p (%d bytes)",
> sasl->mechlist, clientdata, datalen);
> err = sasl_server_start(sasl->conn,
> sasl->mechlist,
> @@ -3210,18 +3210,18 @@ static void reds_handle_auth_sasl_start(void *opaque)
> &serveroutlen);
> if (err != SASL_OK &&
> err != SASL_CONTINUE) {
> - red_printf("sasl start failed %d (%s)",
> - err, sasl_errdetail(sasl->conn));
> + red_warn("sasl start failed %d (%s)",
> + err, sasl_errdetail(sasl->conn));
> goto authabort;
> }
>
> if (serveroutlen > SASL_DATA_MAX_LEN) {
> - red_printf("sasl start reply data too long %d",
> - serveroutlen);
> + red_warn("sasl start reply data too long %d",
> + serveroutlen);
> goto authabort;
> }
>
> - red_printf("SASL return data %d bytes, %p", serveroutlen, serverout);
> + red_log(2, "SASL return data %d bytes, %p", serveroutlen, serverout);
>
> if (serveroutlen) {
> serveroutlen += 1;
> @@ -3235,7 +3235,7 @@ static void reds_handle_auth_sasl_start(void *opaque)
> sync_write_u8(link->stream, err == SASL_CONTINUE ? 0 : 1);
>
> if (err == SASL_CONTINUE) {
> - red_printf("%s", "Authentication must continue (start)");
> + red_log(2, "%s", "Authentication must continue (start)");
> /* Wait for step length */
> obj->now = (uint8_t *)&sasl->len;
> obj->end = obj->now + sizeof(uint32_t);
> @@ -3245,11 +3245,11 @@ static void reds_handle_auth_sasl_start(void *opaque)
> int ssf;
>
> if (auth_sasl_check_ssf(sasl, &ssf) == 0) {
> - red_printf("Authentication rejected for weak SSF");
> + red_warn("Authentication rejected for weak SSF");
> goto authreject;
> }
>
> - red_printf("Authentication successful");
> + red_log(2, "Authentication successful");
> sync_write_u32(link->stream, SPICE_LINK_ERR_OK); /* Accept auth */
>
> /*
> @@ -3279,9 +3279,9 @@ static void reds_handle_auth_startlen(void *opaque)
> AsyncRead *obj = &link->asyc_read;
> RedsSASL *sasl = &link->stream->sasl;
>
> - red_printf("Got client start len %d", sasl->len);
> + red_log(2, "Got client start len %d", sasl->len);
> if (sasl->len > SASL_DATA_MAX_LEN) {
> - red_printf("Too much SASL data %d", sasl->len);
> + red_log(2, "Too much SASL data %d", sasl->len);
> reds_send_link_error(link, SPICE_LINK_ERR_INVALID_DATA);
> reds_link_free(link);
> return;
> @@ -3306,24 +3306,24 @@ static void reds_handle_auth_mechname(void *opaque)
> RedsSASL *sasl = &link->stream->sasl;
>
> sasl->mechname[sasl->len] = '\0';
> - red_printf("Got client mechname '%s' check against '%s'",
> + red_log(2, "Got client mechname '%s' check against '%s'",
> sasl->mechname, sasl->mechlist);
>
> if (strncmp(sasl->mechlist, sasl->mechname, sasl->len) == 0) {
> if (sasl->mechlist[sasl->len] != '\0' &&
> sasl->mechlist[sasl->len] != ',') {
> - red_printf("One %d", sasl->mechlist[sasl->len]);
> + red_log(2, "One %d", sasl->mechlist[sasl->len]);
> reds_link_free(link);
> return;
> }
> } else {
> char *offset = strstr(sasl->mechlist, sasl->mechname);
> - red_printf("Two %p", offset);
> + red_log(2, "Two %p", offset);
> if (!offset) {
> reds_send_link_error(link, SPICE_LINK_ERR_INVALID_DATA);
> return;
> }
> - red_printf("Two '%s'", offset);
> + red_log(2, "Two '%s'", offset);
> if (offset[-1] != ',' ||
> (offset[sasl->len] != '\0'&&
> offset[sasl->len] != ',')) {
> @@ -3335,7 +3335,7 @@ static void reds_handle_auth_mechname(void *opaque)
> free(sasl->mechlist);
> sasl->mechlist = strdup(sasl->mechname);
>
> - red_printf("Validated mechname '%s'", sasl->mechname);
> + red_log(2, "Validated mechname '%s'", sasl->mechname);
>
> obj->now = (uint8_t *)&sasl->len;
> obj->end = obj->now + sizeof(uint32_t);
> @@ -3352,14 +3352,14 @@ static void reds_handle_auth_mechlen(void *opaque)
> RedsSASL *sasl = &link->stream->sasl;
>
> if (sasl->len < 1 || sasl->len > 100) {
> - red_printf("Got bad client mechname len %d", sasl->len);
> + red_log(2, "Got bad client mechname len %d", sasl->len);
> reds_link_free(link);
> return;
> }
>
> sasl->mechname = spice_malloc(sasl->len + 1);
>
> - red_printf("Wait for client mechname");
> + red_log(2, "Wait for client mechname");
> obj->now = (uint8_t *)sasl->mechname;
> obj->end = obj->now + sasl->len;
> obj->done = reds_handle_auth_mechname;
> @@ -3399,8 +3399,8 @@ static void reds_start_auth_sasl(RedLinkInfo *link)
> localAddr = remoteAddr = NULL;
>
> if (err != SASL_OK) {
> - red_printf("sasl context setup failed %d (%s)",
> - err, sasl_errstring(err, NULL, NULL));
> + red_warn("sasl context setup failed %d (%s)",
> + err, sasl_errstring(err, NULL, NULL));
> sasl->conn = NULL;
> goto error;
> }
> @@ -3412,8 +3412,8 @@ static void reds_start_auth_sasl(RedLinkInfo *link)
> ssf = SSL_get_cipher_bits(link->stream->ssl, NULL);
> err = sasl_setprop(sasl->conn, SASL_SSF_EXTERNAL, &ssf);
> if (err != SASL_OK) {
> - red_printf("cannot set SASL external SSF %d (%s)",
> - err, sasl_errstring(err, NULL, NULL));
> + red_warn("cannot set SASL external SSF %d (%s)",
> + err, sasl_errstring(err, NULL, NULL));
> sasl_dispose(&sasl->conn);
> sasl->conn = NULL;
> goto error;
> @@ -3442,8 +3442,8 @@ static void reds_start_auth_sasl(RedLinkInfo *link)
>
> err = sasl_setprop(sasl->conn, SASL_SEC_PROPS, &secprops);
> if (err != SASL_OK) {
> - red_printf("cannot set SASL security props %d (%s)",
> - err, sasl_errstring(err, NULL, NULL));
> + red_warn("cannot set SASL security props %d (%s)",
> + err, sasl_errstring(err, NULL, NULL));
> sasl_dispose(&sasl->conn);
> sasl->conn = NULL;
> goto error;
> @@ -3458,24 +3458,24 @@ static void reds_start_auth_sasl(RedLinkInfo *link)
> NULL,
> NULL);
> if (err != SASL_OK) {
> - red_printf("cannot list SASL mechanisms %d (%s)",
> - err, sasl_errdetail(sasl->conn));
> + red_warn("cannot list SASL mechanisms %d (%s)",
> + err, sasl_errdetail(sasl->conn));
> sasl_dispose(&sasl->conn);
> sasl->conn = NULL;
> goto error;
> }
> - red_printf("Available mechanisms for client: '%s'", mechlist);
> + red_log(2, "Available mechanisms for client: '%s'", mechlist);
>
> sasl->mechlist = strdup(mechlist);
>
> mechlistlen = strlen(mechlist);
> if (!sync_write(link->stream, &mechlistlen, sizeof(uint32_t))
> || !sync_write(link->stream, sasl->mechlist, mechlistlen)) {
> - red_printf("SASL mechanisms write error");
> + red_warn("SASL mechanisms write error");
> goto error;
> }
>
> - red_printf("Wait for client mechname length");
> + red_log(2, "Wait for client mechname length");
> obj->now = (uint8_t *)&sasl->len;
> obj->end = obj->now + sizeof(uint32_t);
> obj->done = reds_handle_auth_mechlen;
> @@ -3493,7 +3493,7 @@ static void reds_handle_auth_mechanism(void *opaque)
> {
> RedLinkInfo *link = (RedLinkInfo *)opaque;
>
> - red_printf("Auth method: %d", link->auth_mechanism.auth_mechanism);
> + red_log(2, "Auth method: %d", link->auth_mechanism.auth_mechanism);
>
> if (link->auth_mechanism.auth_mechanism == SPICE_COMMON_CAP_AUTH_SPICE
> && !sasl_enabled
> @@ -3501,13 +3501,13 @@ static void reds_handle_auth_mechanism(void *opaque)
> reds_get_spice_ticket(link);
> #if HAVE_SASL
> } else if (link->auth_mechanism.auth_mechanism == SPICE_COMMON_CAP_AUTH_SASL) {
> - red_printf("Starting SASL");
> + red_log(2, "Starting SASL");
> reds_start_auth_sasl(link);
> #endif
> } else {
> - red_printf("Unknown auth method, disconnecting");
> + red_warn("Unknown auth method, disconnecting");
> if (sasl_enabled) {
> - red_printf("Your client doesn't handle SASL?");
> + red_warn("Your client doesn't handle SASL?");
> }
> reds_send_link_error(link, SPICE_LINK_ERR_INVALID_DATA);
> reds_link_free(link);
> @@ -3544,10 +3544,10 @@ static void reds_handle_read_link_done(void *opaque)
>
> if (!reds_security_check(link)) {
> if (link->stream->ssl) {
> - red_printf("spice channels %d should not be encrypted", link_mess->channel_type);
> + red_warn("spice channels %d should not be encrypted", link_mess->channel_type);
> reds_send_link_error(link, SPICE_LINK_ERR_NEED_UNSECURED);
> } else {
> - red_printf("spice channels %d should be encrypted", link_mess->channel_type);
> + red_warn("spice channels %d should be encrypted", link_mess->channel_type);
> reds_send_link_error(link, SPICE_LINK_ERR_NEED_SECURED);
> }
> reds_link_free(link);
> @@ -3561,11 +3561,11 @@ static void reds_handle_read_link_done(void *opaque)
>
> if (!auth_selection) {
> if (sasl_enabled) {
> - red_printf("SASL enabled, but peer supports only spice authentication");
> + red_warn("SASL enabled, but peer supports only spice authentication");
> reds_send_link_error(link, SPICE_LINK_ERR_VERSION_MISMATCH);
> return;
> }
> - red_printf("Peer doesn't support AUTH selection");
> + red_warn("Peer doesn't support AUTH selection");
> reds_get_spice_ticket(link);
> } else {
> obj->now = (uint8_t *)&link->auth_mechanism;
> @@ -3583,7 +3583,7 @@ static void reds_handle_link_error(void *opaque, int err)
> case EPIPE:
> break;
> default:
> - red_printf("%s", strerror(errno));
> + red_warn("%s", strerror(errno));
> break;
> }
> reds_link_free(link);
> @@ -3606,7 +3606,7 @@ static void reds_handle_read_header_done(void *opaque)
> reds_send_link_error(link, SPICE_LINK_ERR_VERSION_MISMATCH);
> }
>
> - red_printf("version mismatch");
> + red_warn("version mismatch");
> reds_link_free(link);
> return;
> }
> @@ -3615,7 +3615,7 @@ static void reds_handle_read_header_done(void *opaque)
>
> if (header->size < sizeof(SpiceLinkMess)) {
> reds_send_link_error(link, SPICE_LINK_ERR_INVALID_DATA);
> - red_printf("bad size %u", header->size);
> + red_warn("bad size %u", header->size);
> reds_link_free(link);
> return;
> }
> @@ -3648,7 +3648,7 @@ static void reds_handle_ssl_accept(int fd, int event, void *data)
> if ((return_code = SSL_accept(link->stream->ssl)) != 1) {
> int ssl_error = SSL_get_error(link->stream->ssl, return_code);
> if (ssl_error != SSL_ERROR_WANT_READ && ssl_error != SSL_ERROR_WANT_WRITE) {
> - red_printf("SSL_accept failed, error=%d", ssl_error);
> + red_warn("SSL_accept failed, error=%d", ssl_error);
> reds_link_free(link);
> } else {
> if (ssl_error == SSL_ERROR_WANT_READ) {
> @@ -3672,22 +3672,22 @@ static RedLinkInfo *__reds_accept_connection(int listen_socket)
> int socket;
>
> if ((socket = accept(listen_socket, NULL, 0)) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> return NULL;
> }
>
> if ((flags = fcntl(socket, F_GETFL)) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> goto error;
> }
>
> if (fcntl(socket, F_SETFL, flags | O_NONBLOCK) == -1) {
> - red_printf("accept failed, %s", strerror(errno));
> + red_warn("accept failed, %s", strerror(errno));
> goto error;
> }
>
> if (setsockopt(socket, IPPROTO_TCP, TCP_NODELAY, &delay_val, sizeof(delay_val)) == -1) {
> - red_printf("setsockopt failed, %s", strerror(errno));
> + red_warn("setsockopt failed, %s", strerror(errno));
> }
>
> link = spice_new0(RedLinkInfo, 1);
> @@ -3743,13 +3743,13 @@ static void reds_accept_ssl_connection(int fd, int event, void *data)
>
> // Handle SSL handshaking
> if (!(sbio = BIO_new_socket(link->stream->socket, BIO_NOCLOSE))) {
> - red_printf("could not allocate ssl bio socket");
> + red_warn("could not allocate ssl bio socket");
> goto error;
> }
>
> link->stream->ssl = SSL_new(reds->ctx);
> if (!link->stream->ssl) {
> - red_printf("could not allocate ssl context");
> + red_warn("could not allocate ssl context");
> BIO_free(sbio);
> goto error;
> }
> @@ -3777,7 +3777,7 @@ static void reds_accept_ssl_connection(int fd, int event, void *data)
> }
>
> ERR_print_errors_fp(stderr);
> - red_printf("SSL_accept failed, error=%d", ssl_error);
> + red_warn("SSL_accept failed, error=%d", ssl_error);
> SSL_free(link->stream->ssl);
>
> error:
> @@ -3793,7 +3793,7 @@ static void reds_accept(int fd, int event, void *data)
>
> link = reds_accept_connection(reds->listen_socket);
> if (link == NULL) {
> - red_printf("accept failed");
> + red_warn("accept failed");
> return;
> }
> reds_handle_new_link(link);
> @@ -3842,8 +3842,8 @@ static int reds_init_socket(const char *addr, int portnr, int family)
> }
> close(slisten);
> }
> - red_printf("%s: binding socket to %s:%d failed", __FUNCTION__,
> - addr, portnr);
> + red_warn("%s: binding socket to %s:%d failed", __FUNCTION__,
> + addr, portnr);
> freeaddrinfo(res);
> return -1;
>
> @@ -4070,7 +4070,7 @@ enum {
> static inline void on_activating_ticketing()
> {
> if (!ticketing_enabled && reds->stream) {
> - red_printf("disconnecting");
> + red_warn("disconnecting");
> reds_disconnect();
> }
> }
> @@ -4134,7 +4134,7 @@ static void reds_mig_connect(void)
> SpiceMsgMainMigrationBegin migrate;
> RedsOutItem *item;
>
> - red_printf("");
> + red_log(2, "");
> ASSERT(reds->client_semi_mig_cap);
> item = new_out_item(SPICE_MSG_MAIN_MIGRATE_BEGIN);
>
> @@ -4185,7 +4185,7 @@ static void reds_mig_started(void)
> {
> SpiceMigrateInterface *sif = NULL;
>
> - red_printf("");
> + red_log(2, "");
> ASSERT(reds->mig_spice);
>
> if (!migration_interface) {
> @@ -4197,7 +4197,7 @@ static void reds_mig_started(void)
> reds->mig_connect_ok = FALSE;
>
> if (reds->stream == NULL) {
> - red_printf("not connected to stream");
> + red_warn("not connected to stream");
> reds_mig_release();
> sif->migrate_connect_complete(migration_interface);
> return;
> @@ -4207,7 +4207,7 @@ static void reds_mig_started(void)
> if (reds->client_semi_mig_cap) {
> reds->mig_inprogress = TRUE;
> if (reds->mig_target) {
> - red_printf("previous spice migration hasn't completed yet. Waiting for client");
> + red_log(2, "previous spice migration hasn't completed yet. Waiting for client");
> reds->mig_wait_prev_complete = TRUE;
> core->timer_start(reds->mig_timer, MIGRATE_TIMEOUT);
> } else {
> @@ -4225,10 +4225,10 @@ static void reds_mig_finished(int completed)
> {
> RedsOutItem *item;
>
> - red_printf("");
> + red_log(2, "");
> reds_mig_release();
> ...
>
> [Message clipped]
--
Marc-André Lureau
More information about the Spice-devel
mailing list