[Spice-devel] [spice-server v3 2/2] channel: Introduce logging helpers
Frediano Ziglio
fziglio at redhat.com
Fri Oct 20 11:57:27 UTC 2017
>
> 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.
> ---
> Changes since v2:
> - added red_channel_log_generic macro to limit the amount of copy and
> paste
> - only expand 'channel' once in red_channel_log_generic implementation
>
>
> server/red-channel-client.c | 34 ++++++++++------------------------
> server/red-channel.c | 14 ++++++--------
> server/red-channel.h | 29 +++++++++++++++++++++++++++++
> server/red-qxl.c | 10 ++++------
> server/spicevmc.c | 6 ++----
> 5 files changed, 51 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 c9ab64faa..a9e52cd9f 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 e0fd60a04..de6f13fc4 100644
> --- a/server/red-channel.h
> +++ b/server/red-channel.h
> @@ -236,6 +236,35 @@ 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;
left (_id), right (channel_)!
Is it intentional?
Just to be macro paranoid 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, ...)
> \
> + do {
> \
> + red_channel_log_generic(spice_printerr, channel, format, ##
> __VA_ARGS__); \
> + } while (0)
> +
I would remove the do {} while(0) in these, you are just calling another
macro which is already protected and just couple of lines above.
> +#define red_channel_warning(channel, format, ...)
> \
> + do {
> \
> + red_channel_log_generic(g_warning, channel, format, ## __VA_ARGS__);
> \
> + } while (0)
> +
> +#define red_channel_message(channel, format, ...)
> \
> + do {
> \
> + red_channel_log_generic(g_message, channel, format, ## __VA_ARGS__);
> \
> + } while (0)
> +
> +#define red_channel_debug(channel, format, ...)
> \
> + do {
> \
> + red_channel_log_generic(g_debug, channel, format, ## __VA_ARGS__);
> \
> + } while (0)
> +
> G_END_DECLS
>
> #endif /* RED_CHANNEL_H_ */
> diff --git a/server/red-qxl.c b/server/red-qxl.c
> index 8cf09d9a8..5cdf5f546 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 9daf92b5b..14424912e 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)
> reds_stream_free(stream);
Otherwise is fine for me.
Frediano
More information about the Spice-devel
mailing list