An Untitled Masterwork

flatpak.patch

diff --git a/common/flatpak-transaction.c b/common/flatpak-transaction.c
index 516ecf0a..bff7c7d6 100644
--- a/common/flatpak-transaction.c
+++ b/common/flatpak-transaction.c
@@ -371,6 +371,8 @@ got_progress_cb (const char *status,
                              "start-time", "t", &start_time,
                              NULL);
 
+  g_message ("==FLATPAK PROGRESS== progress on %p calculated as %u%%", p->ostree_progress, progress);
+
   g_free (p->status);
   p->status = g_strdup (status);
   p->progress = progress;
diff --git a/common/flatpak-utils-private.h b/common/flatpak-utils-private.h
index f5862707..147d46a9 100644
--- a/common/flatpak-utils-private.h
+++ b/common/flatpak-utils-private.h
@@ -638,13 +638,20 @@ typedef GFile FlatpakTempDir;
 G_DEFINE_AUTOPTR_CLEANUP_FUNC (FlatpakTempDir, flatpak_temp_dir_destroy)
 
 typedef GMainContext GMainContextPopDefault;
+
+void inc_depth(GMainContext *);
+void dec_depth(GMainContext *);
+
 static inline void
 flatpak_main_context_pop_default_destroy (void *p)
 {
   GMainContext *main_context = p;
 
   if (main_context)
-    g_main_context_pop_thread_default (main_context);
+    {
+      dec_depth (main_context);
+      g_main_context_pop_thread_default (main_context);
+    }
 }
 
 static inline GMainContextPopDefault *
@@ -652,6 +659,7 @@ flatpak_main_context_new_default (void)
 {
   GMainContext *main_context = g_main_context_new ();
 
+  inc_depth (main_context);
   g_main_context_push_thread_default (main_context);
   return main_context;
 }
diff --git a/common/flatpak-utils.c b/common/flatpak-utils.c
index 0ba5e909..e4c09384 100644
--- a/common/flatpak-utils.c
+++ b/common/flatpak-utils.c
@@ -82,6 +82,25 @@ static const GDBusErrorEntry flatpak_error_entries[] = {
 typedef struct archive FlatpakAutoArchiveRead;
 G_DEFINE_AUTOPTR_CLEANUP_FUNC (FlatpakAutoArchiveRead, archive_read_free)
 
+static volatile int depth = 0;
+
+void
+dec_depth (GMainContext *main_context)
+{
+  g_atomic_int_dec_and_test (&depth);
+  g_message ("==CONTEXT== Popping context %p, depth %d", main_context,
+             g_atomic_int_get(&depth));
+}
+
+void
+inc_depth (GMainContext *main_context)
+{
+  g_atomic_int_inc (&depth);
+  g_message ("==CONTEXT== Pushing context %p to replace %p, depth %d",
+             main_context, g_main_context_get_thread_default (),
+             g_atomic_int_get (&depth));
+}
+
 static void
 propagate_libarchive_error (GError        **error,
                             struct archive *a)
@@ -6218,6 +6237,8 @@ progress_cb (OstreeAsyncProgress *progress, gpointer user_data)
   g_autofree gchar *formatted_bytes_total_transferred = NULL;
   g_autoptr(GVariant) outstanding_fetchesv = NULL;
 
+  g_message ("==FLATPAK PROGRESS== OstreeAsyncProgress signal fired on %p", progress);
+
   /* We get some extra calls before we've really started due to the initialization of the
      extra data, so ignore those */
   outstanding_fetchesv = ostree_async_progress_get_variant (progress, "outstanding-fetches");

ostree.patch

diff --git a/src/libostree/ostree-async-progress.c b/src/libostree/ostree-async-progress.c
index a8e629ee..36e7b26a 100644
--- a/src/libostree/ostree-async-progress.c
+++ b/src/libostree/ostree-async-progress.c
@@ -231,6 +231,8 @@ idle_invoke_async_progress (gpointer user_data)
   g_clear_pointer (&self->idle_source, g_source_unref);
   g_mutex_unlock (&self->lock);
 
+  g_message ("%p's idle invoked on context %p", self, self->maincontext);
+
   g_signal_emit (self, signals[CHANGED], 0);
 
   return FALSE;
@@ -350,6 +352,9 @@ ostree_async_progress_set (OstreeAsyncProgress *self,
           g_variant_equal (orig_value, new_value))
         continue;
 
+      char *dump = g_variant_print (new_value, FALSE);
+      g_message ("%p: %s=%s", self, key, dump);
+      g_free (dump);
       g_hash_table_replace (self->values, qkey, g_steal_pointer (&new_value));
       changed = TRUE;
     }
@@ -401,6 +406,11 @@ ostree_async_progress_set_variant (OstreeAsyncProgress *self,
       if (g_variant_equal (orig_value, new_value))
         goto out;
     }
+
+  char *dump = g_variant_print (new_value, FALSE);
+  g_message ("%p: %s=%s", self, key, dump);
+  g_free (dump);
+
   g_hash_table_replace (self->values, qkey, g_steal_pointer (&new_value));
   ensure_callback_locked (self);
 
@@ -472,5 +482,8 @@ ostree_async_progress_finish (OstreeAsyncProgress *self)
   g_mutex_unlock (&self->lock);
 
   if (emit_changed)
-    g_signal_emit (self, signals[CHANGED], 0);
+    {
+      g_message ("emitting last progress event on %p, context %p", self, self->maincontext);
+      g_signal_emit (self, signals[CHANGED], 0);
+    }
 }

output.txt

$ FLATPAK_FANCY_OUTPUT=0 flatpak install flathub org.gnome.PowerStats
Looking for matches…
F: ==CONTEXT== Pushing context 0x563a21758960 to replace (nil), depth 1
F: ==CONTEXT== Pushing context 0x563a21759fa0 to replace 0x563a21758960, depth 2
F: ==CONTEXT== Popping context 0x563a21759fa0, depth 1
F: ==CONTEXT== Pushing context 0x563a217488a0 to replace 0x563a21758960, depth 2
F: ==CONTEXT== Popping context 0x563a217488a0, depth 1
F: ==CONTEXT== Pushing context 0x563a2183f940 to replace 0x563a21758960, depth 2
F: ==CONTEXT== Popping context 0x563a2183f940, depth 1

org.gnome.PowerStats permissions:
    ipc	wayland	x11	file access [1]
    dbus access [2]	system dbus access [3]

    [1] xdg-run/dconf, ~/.config/dconf:ro
    [2] ca.desrt.dconf
    [3] org.freedesktop.UPower


 1.	   	org.gnome.PowerStats.Locale	stable	flathub	< 322.9 kB (partial)
 2.	   	org.gnome.PowerStats	stable	flathub	< 586.1 kB

Proceed with these changes to the system installation? [Y/n]: y
Warning: ==CONTEXT== Pushing context 0x563a2177fb50 to replace 0x563a21758960, depth 2
Warning: ==CONTEXT== Popping context 0x563a2177fb50, depth 1                    
OSTree-Message: 12:42:03.167: 0x7f000c3e94c0: outstanding-extra-data=0
OSTree-Message: 12:42:03.167: 0x7f000c3e94c0: total-extra-data=0
OSTree-Message: 12:42:03.167: 0x7f000c3e94c0: total-extra-data-bytes=0
OSTree-Message: 12:42:03.167: 0x7f000c3e94c0: transferred-extra-data-bytes=0
OSTree-Message: 12:42:03.167: 0x7f000c3e94c0: downloading-extra-data=0
Warning: ==CONTEXT== Pushing context 0x563a217bb3e0 to replace 0x563a21758960, depth 2
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: outstanding-fetches=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: outstanding-writes=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: fetched=4
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: requested=4
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: scanning=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: caught-error=false
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: scanned-metadata=3
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: bytes-transferred=5921
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: start-time=61195948914
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: metadata-fetched-localcache=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: content-fetched-localcache=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: fetched-delta-parts=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: total-delta-parts=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: fetched-delta-fallbacks=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: total-delta-fallbacks=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: fetched-delta-part-size=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: total-delta-part-size=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: total-delta-part-usize=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: total-delta-superblocks=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: outstanding-metadata-fetches=0
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: metadata-fetched=3
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: status=''
OSTree-Message: 12:42:07.351: 0x7f000c3e94c0: status='3 metadata, 1 content objects fetched; 5 KiB transferred in 2 seconds'
Warning: ==CONTEXT== Popping context 0x563a217bb3e0, depth 1                    
OSTree-Message: 12:42:07.354: emitting last progress event on 0x7f000c3e94c0, context 0x563a21758960
Warning: ==FLATPAK PROGRESS== OstreeAsyncProgress signal fired on 0x7f000c3e94c0
Warning: ==FLATPAK PROGRESS== progress on 0x7f000c3e94c0 calculated as 100%     
Warning: ==CONTEXT== Pushing context 0x563a2177c140 to replace 0x563a21758960, depth 2
Warning: ==CONTEXT== Popping context 0x563a2177c140, depth 1                    
OSTree-Message: 12:42:12.210: 0x7f0010005b00: outstanding-extra-data=0
OSTree-Message: 12:42:12.210: 0x7f0010005b00: total-extra-data=0
OSTree-Message: 12:42:12.210: 0x7f0010005b00: total-extra-data-bytes=0
OSTree-Message: 12:42:12.210: 0x7f0010005b00: transferred-extra-data-bytes=0
OSTree-Message: 12:42:12.210: 0x7f0010005b00: downloading-extra-data=0
Warning: ==CONTEXT== Pushing context 0x563a217ff610 to replace 0x563a21758960, depth 2
OSTree-Message: 12:42:17.346: 0x7f0010005b00: outstanding-fetches=8
OSTree-Message: 12:42:17.346: 0x7f0010005b00: outstanding-writes=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: fetched=27
OSTree-Message: 12:42:17.346: 0x7f0010005b00: requested=46
OSTree-Message: 12:42:17.346: 0x7f0010005b00: scanning=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: caught-error=false
OSTree-Message: 12:42:17.346: 0x7f0010005b00: scanned-metadata=23
OSTree-Message: 12:42:17.346: 0x7f0010005b00: bytes-transferred=66213
OSTree-Message: 12:42:17.346: 0x7f0010005b00: start-time=61205568446
OSTree-Message: 12:42:17.346: 0x7f0010005b00: metadata-fetched-localcache=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: content-fetched-localcache=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: fetched-delta-parts=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: total-delta-parts=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: fetched-delta-fallbacks=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: total-delta-fallbacks=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: fetched-delta-part-size=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: total-delta-part-size=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: total-delta-part-usize=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: total-delta-superblocks=0
OSTree-Message: 12:42:17.346: 0x7f0010005b00: outstanding-metadata-fetches=8
OSTree-Message: 12:42:17.346: 0x7f0010005b00: metadata-fetched=22
OSTree-Message: 12:42:17.346: 0x7f0010005b00: status=''
OSTree-Message: 12:42:17.647: 0x7f0010005b00: outstanding-fetches=1
OSTree-Message: 12:42:17.647: 0x7f0010005b00: fetched=67
OSTree-Message: 12:42:17.647: 0x7f0010005b00: requested=68
OSTree-Message: 12:42:17.647: 0x7f0010005b00: scanned-metadata=45
OSTree-Message: 12:42:17.647: 0x7f0010005b00: bytes-transferred=569299
OSTree-Message: 12:42:17.647: 0x7f0010005b00: outstanding-metadata-fetches=1
OSTree-Message: 12:42:17.647: 0x7f0010005b00: metadata-fetched=44
OSTree-Message: 12:42:22.421: 0x7f0010005b00: outstanding-fetches=0
OSTree-Message: 12:42:22.421: 0x7f0010005b00: fetched=70
OSTree-Message: 12:42:22.421: 0x7f0010005b00: requested=70
OSTree-Message: 12:42:22.421: 0x7f0010005b00: scanned-metadata=47
OSTree-Message: 12:42:22.421: 0x7f0010005b00: bytes-transferred=571392
OSTree-Message: 12:42:22.421: 0x7f0010005b00: outstanding-metadata-fetches=0
OSTree-Message: 12:42:22.421: 0x7f0010005b00: metadata-fetched=46
OSTree-Message: 12:42:22.422: 0x7f0010005b00: status='46 metadata, 24 content objects fetched; 558 KiB transferred in 7 seconds'
Warning: ==CONTEXT== Popping context 0x563a217ff610, depth 1                    
OSTree-Message: 12:42:22.427: emitting last progress event on 0x7f0010005b00, context 0x563a21758960
Warning: ==FLATPAK PROGRESS== OstreeAsyncProgress signal fired on 0x7f0010005b00
Warning: ==FLATPAK PROGRESS== progress on 0x7f0010005b00 calculated as 100%     
Warning: ==CONTEXT== Popping context 0x563a21758960, depth 0                    
Installation complete.