[Spice-devel] [spice-server 2/5] channel: Introduce logging helpers

Jonathon Jongsma jjongsma at redhat.com
Tue Oct 17 20:37:00 UTC 2017


Despite my misgivings about calling _printerr() with an empty string...

Acked-by: Jonathon Jongsma <jjongsma at redhat.com>


On Thu, 2017-10-12 at 12:13 +0200, Christophe Fergeau wrote:
> 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.
> ---
>  server/red-channel-client.c | 34 ++++++++++------------------------
>  server/red-channel.c        | 14 ++++++--------
>  server/red-channel.h        | 32 ++++++++++++++++++++++++++++++++
>  server/red-qxl.c            | 10 ++++------
>  server/spicevmc.c           |  6 ++----
>  5 files changed, 54 insertions(+), 42 deletions(-)
> 
> diff --git a/server/red-channel-client.c b/server/red-channel-
> client.c
> index bd14be32a..ca0a6d19f 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 4e5aba474..2327fbdab 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);
>  
> @@ -471,12 +471,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 861887ed4..72f66eda0 100644
> --- a/server/red-channel.h
> +++ b/server/red-channel.h
> @@ -239,6 +239,38 @@ void red_channel_disconnect_client(RedChannel
> *channel, RedChannelClient *rcc);
>  
>  #define CHANNEL_BLOCKED_SLEEP_DURATION 10000 //micro
>  
> +#define red_channel_printerr(channel, format,
> ...)                                       \
> +    do
> {                                                                    
>              \
> +        uint32_t
> _id;                                                                 
>    \
> +        g_object_get(channel, "id", &_id,
> NULL);                                         \
> +        spice_printerr("%s:%u (%p): " format,
> red_channel_get_name(channel),             \
> +                        _id, channel, ##
> __VA_ARGS__);                                   \
> +    } while (0)
> +
> +#define red_channel_warning(channel, format,
> ...)                                        \
> +    do
> {                                                                    
>              \
> +        uint32_t
> _id;                                                                 
>    \
> +        g_object_get(channel, "id", &_id,
> NULL);                                         \
> +        g_warning("%s:%u (%p): " format,
> red_channel_get_name(channel),                  \
> +                  _id, channel, ##
> __VA_ARGS__);                                         \
> +    } while (0)
> +
> +#define red_channel_message(channel, format,
> ...)                                        \
> +    do
> {                                                                    
>              \
> +        uint32_t
> _id;                                                                 
>    \
> +        g_object_get(channel, "id", &_id,
> NULL);                                         \
> +        g_message("%s:%u (%p): " format,
> red_channel_get_name(channel),                  \
> +                  _id, channel, ##
> __VA_ARGS__);                                         \
> +    } while (0)
> +
> +#define red_channel_debug(channel, format,
> ...)                                          \
> +    do
> {                                                                    
>              \
> +        uint32_t
> _id;                                                                 
>    \
> +        g_object_get(channel, "id", &_id,
> NULL);                                         \
> +        g_debug("%s:%u (%p): " format,
> red_channel_get_name(channel),                    \
> +                _id, channel, ##
> __VA_ARGS__);                                           \
> +    } while (0)
> +
>  G_END_DECLS
>  
>  #endif /* RED_CHANNEL_H_ */
> diff --git a/server/red-qxl.c b/server/red-qxl.c
> index 336bb2e68..ad9a99efe 100644
> --- a/server/red-qxl.c
> +++ b/server/red-qxl.c
> @@ -115,11 +115,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,
> @@ -165,11 +164,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 45036c470..fb760944b 100644
> --- a/server/spicevmc.c
> +++ b/server/spicevmc.c
> @@ -806,15 +806,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)
>          reds_stream_free(stream);


More information about the Spice-devel mailing list