channel: Introduce logging helpers

This commit adds red_channel_{debug,warning,printerr}() helpers which
will prepend the log message with "channel-name:id (%p)". It also
changes various locations which were doing this manually.

Acked-by: Frediano Ziglio <fziglio@redhat.com>

5 files changed, 43 insertions, 42 deletions

diff --git a/server/red-channel-client.c b/server/red-channel-client.c
index 54a6223b..821dd351 100644
--- a/server/red-channel-client.c
+++ b/server/red-channel-client.c
@@ -181,10 +181,7 @@ static bool red_channel_client_config_socket(RedChannelClient *rcc);
 #define spice_channel_client_error(rcc, format, ...)                                     \
     do {                                                                                 \
         RedChannel *_ch = red_channel_client_get_channel(rcc);                           \
-        uint32_t _type, _id;                                                             \
-        g_object_get(_ch, "channel-type", &_type, "id", &_id, NULL);                     \
-        spice_warning("rcc %p type %u id %u: " format, rcc,                              \
-                    type, id, ## __VA_ARGS__);                                           \
+        red_channel_warning(_ch, format, ## __VA_ARGS__);                                \
         red_channel_client_shutdown(rcc);                                                \
     } while (0)
 
@@ -778,14 +775,10 @@ static void red_channel_client_connectivity_timer(void *opaque)
         core->timer_start(core, rcc->priv->connectivity_monitor.timer,
                           rcc->priv->connectivity_monitor.timeout);
     } else {
-        uint32_t type, id;
-        g_object_get(rcc->priv->channel,
-                     "channel-type", &type,
-                     "id", &id,
-                     NULL);
         monitor->state = CONNECTIVITY_STATE_DISCONNECTED;
-        spice_warning("rcc %p on channel %d:%d has been unresponsive for more than %u ms, disconnecting",
-                      rcc, type, id, monitor->timeout);
+        red_channel_warning(rcc->priv->channel,
+                            "rcc %p has been unresponsive for more than %u ms, disconnecting",
+                            rcc, monitor->timeout);
         red_channel_client_disconnect(rcc);
     }
 }
@@ -1419,11 +1412,9 @@ static void red_channel_client_handle_migrate_data(RedChannelClient *rcc,
 {
     RedChannel *channel = red_channel_client_get_channel(rcc);
     RedChannelClass *klass = RED_CHANNEL_GET_CLASS(channel);
-    uint32_t type, id;
 
-    g_object_get(channel, "channel-type", &type, "id", &id, NULL);
-    spice_debug("channel type %d id %d rcc %p size %u",
-                type, id, rcc, size);
+    red_channel_debug(channel, "rcc %p size %u", rcc, size);
+
     if (!klass->handle_migrate_data) {
         return;
     }
@@ -1709,14 +1700,11 @@ void red_channel_client_disconnect(RedChannelClient *rcc)
 {
     RedChannel *channel = rcc->priv->channel;
     SpiceCoreInterfaceInternal *core = red_channel_get_core_interface(channel);
-    uint32_t type, id;
 
     if (!red_channel_client_is_connected(rcc)) {
         return;
     }
-    g_object_get(channel, "channel-type", &type, "id", &id, NULL);
-    spice_printerr("rcc=%p (channel=%p type=%d id=%d)", rcc, channel,
-                   type, id);
+    red_channel_printerr(channel, "rcc=%p", rcc);
     red_channel_client_pipe_clear(rcc);
     if (rcc->priv->stream->watch) {
         core->watch_remove(core, rcc->priv->stream->watch);
@@ -1881,19 +1869,17 @@ void red_channel_client_pipe_remove_and_release_pos(RedChannelClient *rcc,
 gboolean red_channel_client_set_migration_seamless(RedChannelClient *rcc)
 {
     gboolean ret = FALSE;
-    uint32_t type, id, flags;
+    uint32_t flags;
 
     g_object_get(rcc->priv->channel,
-                 "channel-type", &type,
-                 "id", &id,
                  "migration-flags", &flags,
                  NULL);
     if (flags & SPICE_MIGRATE_NEED_DATA_TRANSFER) {
         rcc->priv->wait_migrate_data = TRUE;
         ret = TRUE;
     }
-    spice_debug("channel type %d id %d rcc %p wait data %d", type, id, rcc,
-                rcc->priv->wait_migrate_data);
+    red_channel_debug(rcc->priv->channel, "rcc %p wait data %d", rcc,
+                      rcc->priv->wait_migrate_data);
 
     return ret;
 }
diff --git a/server/red-channel.c b/server/red-channel.c
index b3e98abc..ad45fb52 100644
--- a/server/red-channel.c
+++ b/server/red-channel.c
@@ -191,8 +191,8 @@ static void
 red_channel_constructed(GObject *object)
 {
     RedChannel *self = RED_CHANNEL(object);
-    spice_debug("%p: channel type %d id %d thread_id 0x%lx", self,
-                self->priv->type, self->priv->id, self->priv->thread_id);
+
+    red_channel_debug(self, "thread_id 0x%lx", self->priv->thread_id);
 
     RedChannelClass *klass = RED_CHANNEL_GET_CLASS(self);
 
@@ -463,12 +463,10 @@ void red_channel_remove_client(RedChannel *channel, RedChannelClient *rcc)
     g_return_if_fail(channel == red_channel_client_get_channel(rcc));
 
     if (!pthread_equal(pthread_self(), channel->priv->thread_id)) {
-        spice_warning("channel type %d id %d - "
-                      "channel->thread_id (0x%lx) != pthread_self (0x%lx)."
-                      "If one of the threads is != io-thread && != vcpu-thread, "
-                      "this might be a BUG",
-                      channel->priv->type, channel->priv->id,
-                      channel->priv->thread_id, pthread_self());
+        red_channel_warning(channel, "channel->thread_id (0x%lx) != pthread_self (0x%lx)."
+                            "If one of the threads is != io-thread && != vcpu-thread, "
+                            "this might be a BUG",
+                            channel->priv->thread_id, pthread_self());
     }
     spice_return_if_fail(channel);
     link = g_list_find(channel->priv->clients, rcc);
diff --git a/server/red-channel.h b/server/red-channel.h
index 70282197..9e64e8b1 100644
--- a/server/red-channel.h
+++ b/server/red-channel.h
@@ -236,6 +236,27 @@ void red_channel_disconnect_client(RedChannel *channel, RedChannelClient *rcc);
 
 #define CHANNEL_BLOCKED_SLEEP_DURATION 10000 //micro
 
+#define red_channel_log_generic(log_cb, channel, format, ...)                            \
+    do {                                                                                 \
+        uint32_t id_;                                                                    \
+        RedChannel *channel_ = (channel);                                                \
+        g_object_get(channel_, "id", &id_, NULL);                                        \
+        log_cb("%s:%u (%p): " format, red_channel_get_name(channel_),                    \
+                        id_, channel_, ## __VA_ARGS__);                                  \
+    } while (0)
+
+#define red_channel_printerr(channel, format, ...)                                       \
+        red_channel_log_generic(spice_printerr, channel, format, ## __VA_ARGS__);
+
+#define red_channel_warning(channel, format, ...)                                        \
+        red_channel_log_generic(g_warning, channel, format, ## __VA_ARGS__);
+
+#define red_channel_message(channel, format, ...)                                        \
+        red_channel_log_generic(g_message, channel, format, ## __VA_ARGS__);
+
+#define red_channel_debug(channel, format, ...)                                          \
+        red_channel_log_generic(g_debug, channel, format, ## __VA_ARGS__);
+
 G_END_DECLS
 
 #endif /* RED_CHANNEL_H_ */
diff --git a/server/red-qxl.c b/server/red-qxl.c
index ad33b1b4..730b9f3d 100644
--- a/server/red-qxl.c
+++ b/server/red-qxl.c
@@ -114,11 +114,10 @@ static void red_qxl_display_migrate(RedChannelClient *rcc)
     RedWorkerMessageDisplayMigrate payload;
     Dispatcher *dispatcher;
     RedChannel *channel = red_channel_client_get_channel(rcc);
-    uint32_t type, id;
 
-    g_object_get(channel, "channel-type", &type, "id", &id, NULL);
+    red_channel_printerr(channel, "");
+
     dispatcher = (Dispatcher *)g_object_get_data(G_OBJECT(channel), "dispatcher");
-    spice_printerr("channel type %u id %u", type, id);
     payload.rcc = g_object_ref(rcc);
     dispatcher_send_message(dispatcher,
                             RED_WORKER_MESSAGE_DISPLAY_MIGRATE,
@@ -164,11 +163,10 @@ static void red_qxl_cursor_migrate(RedChannelClient *rcc)
     RedWorkerMessageCursorMigrate payload;
     Dispatcher *dispatcher;
     RedChannel *channel = red_channel_client_get_channel(rcc);
-    uint32_t type, id;
 
-    g_object_get(channel, "channel-type", &type, "id", &id, NULL);
+    red_channel_printerr(channel, "");
+
     dispatcher = (Dispatcher *)g_object_get_data(G_OBJECT(channel), "dispatcher");
-    spice_printerr("channel type %u id %u", type, id);
     payload.rcc = g_object_ref(rcc);
     dispatcher_send_message(dispatcher,
                             RED_WORKER_MESSAGE_CURSOR_MIGRATE,
diff --git a/server/spicevmc.c b/server/spicevmc.c
index 42ed2eb3..6a6e6202 100644
--- a/server/spicevmc.c
+++ b/server/spicevmc.c
@@ -804,15 +804,13 @@ static void spicevmc_connect(RedChannel *channel, RedClient *client,
     RedVmcChannel *vmc_channel;
     SpiceCharDeviceInstance *sin;
     SpiceCharDeviceInterface *sif;
-    uint32_t type, id;
 
     vmc_channel = RED_VMC_CHANNEL(channel);
     sin = vmc_channel->chardev_sin;
-    g_object_get(channel, "channel-type", &type, "id", &id, NULL);
 
     if (vmc_channel->rcc) {
-        spice_printerr("channel client %d:%d (%p) already connected, refusing second connection",
-                       type, id, vmc_channel->rcc);
+        red_channel_printerr(channel, "channel client (%p) already connected, refusing second connection",
+                             vmc_channel->rcc);
         // TODO: notify client in advance about the in use channel using
         // SPICE_MSG_MAIN_CHANNEL_IN_USE (for example)
         red_stream_free(stream);