[Spice-devel] [spice-gtk v1 2/2] gtk-session: clipboard: add some more debugs

[Jakub Janku]

Hi,

On Mon, Jan 28, 2019 at 1:23 PM Victor Toso <victortoso at redhat.com> wrote:
>
> From: Victor Toso <me at victortoso.com>
>
> To help track race conditions and bad/unexpected behavior in general.

Awesome! I was planning on sending something similar too.
>
> Signed-off-by: Victor Toso <victortoso at redhat.com>
> ---
>  src/spice-gtk-session.c | 24 ++++++++++++++++--------
>  1 file changed, 16 insertions(+), 8 deletions(-)
>
> diff --git a/src/spice-gtk-session.c b/src/spice-gtk-session.c
> index ac2ba0b..bdb1d9d 100644
> --- a/src/spice-gtk-session.c
> +++ b/src/spice-gtk-session.c
> @@ -544,7 +544,7 @@ static void clipboard_handler_get_targets_cb(GtkClipboard *clipboard,
>  {
>      SpiceGtkSession *self = free_weak_ref(user_data);
>
> -    SPICE_DEBUG("%s:", __FUNCTION__);
> +    SPICE_DEBUG("%s natoms=%d from %p", __func__, n_atoms, clipboard);

Printing the address clipboard points to is rather useless imho. The
corresponding selection id is what we're interested in.
>
>      if (self == NULL)
>          return;
> @@ -704,9 +704,10 @@ client_clipboard_received_data(SpiceMainChannel *main,
>      SpiceGtkSessionPrivate *s = ri->self->priv;
>      gchar *conv = NULL;
>
> -    g_return_if_fail(selection == ri->selection);
> +    SPICE_DEBUG("%s %u bytes (%p) for sel=%u type=%u",
> +                __func__, size, data, selection, type);
>
> -    SPICE_DEBUG("clipboard got data");
> +    g_return_if_fail(selection == ri->selection);
>
>      if (atom2agent[ri->info].vdagent == VD_AGENT_CLIPBOARD_UTF8_TEXT) {
>          /* on windows, gtk+ would already convert to LF endings, but
> @@ -751,12 +752,11 @@ client_clipboard_request_data(GtkClipboard *clipboard,
>      gboolean agent_connected = FALSE;
>      gulong clipboard_handler;
>      gulong agent_handler;
> -    int selection;
>
> -    SPICE_DEBUG("clipboard get");
> -
> -    selection = get_selection_from_clipboard(s, clipboard);
> +    int selection = get_selection_from_clipboard(s, clipboard);
>      g_return_if_fail(selection != -1);
> +    SPICE_DEBUG("%s for sel=%d (%p)", __func__, selection, clipboard);

Maybe also print the type that is being requested (info,
atom2agent[info].vdagent) ?
> +
>      g_return_if_fail(info < SPICE_N_ELEMENTS(atom2agent));
>      g_return_if_fail(s->main != NULL);
>
> @@ -801,7 +801,7 @@ cleanup:
>  static void
>  clipboard_handler_clear(GtkClipboard *clipboard, gpointer user_data)
>  {
> -    SPICE_DEBUG("clipboard_clear");
> +    SPICE_DEBUG("%s on %p", __func__, clipboard);

Same as above: print selection instead of pointer's address

>      /* We watch for clipboard ownership changes and act on those, so we
>         don't need to do anything here */
>  }
> @@ -846,6 +846,9 @@ guest_clipboard_grab(SpiceMainChannel *main,
>          }
>      }
>
> +    SPICE_DEBUG("%s selection=%u (%p), might request %d/%u types",
> +                __func__, selection, cb, num_targets, ntypes);

When we send a grab to vdagent, we print each target (atom's name).
Maybe we could do that here as well?
> +
>      g_free(s->clip_targets[selection]);
>      s->nclip_targets[selection] = num_targets;
>      s->clip_targets[selection] = g_memdup(targets, sizeof(GtkTargetEntry) * num_targets);
> @@ -1014,6 +1017,7 @@ guest_clipboard_request_send_data(GtkClipboard *clipboard,
>       */
>      g_warn_if_fail(type != VD_AGENT_CLIPBOARD_UTF8_TEXT);
>
> +    SPICE_DEBUG("%s %d bytes for selection=%d (%p) type=%u", __func__, len, selection, clipboard, type);

Split into two lines?

>      spice_main_channel_clipboard_selection_notify(s->main, selection, type, data, len);
>  }
>
> @@ -1034,6 +1038,8 @@ guest_clipboard_request_data(SpiceMainChannel *main,
>
>      cb = get_clipboard_from_selection(s, selection);
>      g_return_val_if_fail(cb != NULL, FALSE);
> +    SPICE_DEBUG("%s selection=%u (%p) type=%u", __func__, selection, cb, type);
> +
>      g_return_val_if_fail(s->clipboard_by_guest[selection] == FALSE, FALSE);
>      g_return_val_if_fail(s->clip_grabbed[selection], FALSE);
>
> @@ -1072,6 +1078,8 @@ guest_clipboard_release(SpiceMainChannel *main,
>      SpiceGtkSessionPrivate *s = self->priv;
>      GtkClipboard* clipboard = get_clipboard_from_selection(s, selection);
>
> +    SPICE_DEBUG("%s selection=%u (%p)", __func__, selection, clipboard);
> +
>      if (!clipboard)
>          return;
>
> --
> 2.20.1
>

In some logs, you use "sel=" while in others "selection=".

I think owner-change deserves a log too.
Logs in clipboard_handler_received_text_cb() could contain the
concerned selection.

Regards,
Jakub