[Spice-devel] [PATCH server 0.8 1/3] server: introduce red_log and red_warn
Alon Levy
alevy at redhat.com
Sun Oct 9 10:02:20 PDT 2011
On Sun, Oct 09, 2011 at 06:37:30PM +0200, Marc-André Lureau wrote:
> 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()?
The point was to add some log levels, 1 is LOG_WARN. I can make 2
LOG_DEBUG, then that 2 goes away, but anyone can add a red_log(3,
"blah") visible only with SPICE_LOG_LEVEL=3+.
>
> > ---
> > 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