Win32: ngl/vulkan slow animations

Hi,

In gtk4’s “main” development branch, the old “gl” renderer was recently dropped.
With the latest official ngl/vulkan renderers, I noticed that some animations (like spinners) seem to take all the mainloop time allocation.

Context: I start a GtkSpinner, load a file in a thread, then once done notify the mainloop with idle_add() to stop the spinner.
Problem: the file gets loaded but my idle callback is never called, the Spinner keeps running.

When I break the execution with gdb and print the backtrace, I see that the app spends most of its time in gdk_frame_clock_paint_idle. I suspect the painting has higher priority and monopolizes the mainloop for itself, so lower-prio events are not processed, like my idle callback.
Note that the UI is not frozen and reacts to key/clicks, which makes sense because they’ve higher prio.

If I disable animations (gtk-enable-animation setting), or use the cairo or the old gl renderer (last gtk commit before its removal), then the issue doesn’t occur.

My setup: Windows11, Intel TigerLake iGPU
I compile gtk myself but also saw the issue with the official gtk-4.16.12 from msys2-ucrt64.

Has anyone an idea about what could be going wrong?

Hi @gwillems,

I add this code to gtk4-widget-factory:

diff --git a/demos/widget-factory/widget-factory.c b/demos/widget-factory/widget-factory.c
index 362a4a59e2..02a7bf6188 100644
--- a/demos/widget-factory/widget-factory.c
+++ b/demos/widget-factory/widget-factory.c
@@ -2125,6 +2125,22 @@ load_texture_in_thread (GtkWidget  *picture,
   g_object_unref (task);
 }

+static gboolean
+on_idle (gpointer user_data)
+{
+  g_print ("Idle callback\n");
+
+  return G_SOURCE_REMOVE;
+}
+
+static gboolean
+on_timeout (gpointer user_data)
+{
+  g_idle_add_full (G_PRIORITY_LOW, on_idle, NULL, NULL);
+
+  return G_SOURCE_CONTINUE;
+}
+
 static void
 activate (GApplication *app)
 {
@@ -2497,6 +2513,8 @@ G_GNUC_END_IGNORE_DEPRECATIONS

   gtk_window_present (window);

+  g_timeout_add_seconds_full (G_PRIORITY_LOW, 2, on_timeout, NULL, NULL);
+
   g_object_unref (builder);
 }


I can see regular printouts in the terminal. By the way, can you check your framerate?

  • Open the inspector
  • Global tab
  • Settings pane
  • Scroll down and enable Show Framerate

Hi,

I checked with gtk4-widget-factory but could not reproduce the issue with it.

The affected app framerate drops to ~26fps during the slowdown.
I added a low-prio heartbeat printf just like you suggested, and confirm it’s not called when the spinner animation is running.
Interesting point is that I only observe that when the app is maximized. Once unmaximized, I get the callback called, though after a few seconds lag.

I would love to have a sysprof-like tool on Windows for profiling, do you know some equivalent?

Yes, but you’ll have to compile the stack with MSVC to get meaningful backtraces. You might use a package manager like vcpkg or gvsbuild, or build everything with Meson ( -Dwrap_mode=forcefallback).

Ok, I can reproduce with gtk4-widget-factory by adding an artificial Sleep(200) in gdk_win32_gl_context_wgl_end_frame (and forcing the GL renderer, since GSK defaults to Vulkan now)

This makes sense: GdkFrameClockIdle, despite the name, uses a timeout GSource set to 60Hz (about 16 milliseconds). If painting takes long, the timeout source will always be ready, and lower-priority GSources are starved.

Theoretically, we could make the GdkFrameClockIdle source never return ready from prepare and return at least 1 millisecond. So even if we can’t keep up with the target framerate, we still flush low-prio sources.

1 Like

I wonder why Cairo is faster than NGL. Is OpenGL emulated in software, e.g llvmpipe or VM?

No idea… I don’t think any kind of emulation is involved, i’m just using the cairo binaries provided by msys2-ucrt64.

I got some backtraces when breaking with ctrl+c , if that may help:

NGL backtrace
Thread 1 (Thread 18984.0x3e8c):
#0  0x00007ffde7d23ad0 in ntdll!RtlCompareMemoryUlong () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#1  0x00007ffde7c0ab21 in ntdll!RtlProtectHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#2  0x00007ffde7bdc20e in ntdll!RtlAllocateHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#3  0x00007ffde7bdbe86 in ntdll!RtlAllocateHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#4  0x00007ffde7c7abbc in ntdll!RtlGetUserInfoHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#5  0x00007ffde7c0b8c3 in ntdll!RtlProtectHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#6  0x00007ffde7bdc20e in ntdll!RtlAllocateHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#7  0x00007ffde7bdbe86 in ntdll!RtlAllocateHeap () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#8  0x00007ffd7b0f7544 in igxelpicd64!DumpRegistryKeyDefinitions () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#9  0x00007ffd7b0cabdf in igxelpicd64!DumpRegistryKeyDefinitions () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#10 0x00007ffd7b1751f3 in igxelpicd64!DumpRegistryKeyDefinitions () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#11 0x00007ffd7b195aa0 in igxelpicd64!DumpRegistryKeyDefinitions () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#12 0x00007ffd7aad62c8 in igxelpicd64!DumpRegistryKeyDefinitions () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#13 0x00007ffd7a96f34c in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#14 0x00007ffd7a96c964 in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#15 0x00007ffd7a8d214c in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#16 0x00007ffd7a8d27fc in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#17 0x00007ffd7a8c8c61 in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#18 0x00007ffd7a8c5147 in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#19 0x00007ffd7a8cadd8 in igxelpicd64!RegisterProcTableCallback () from C:\WINDOWS\System32\DriverStore\FileRepository\iigd_dch.inf_amd64_b2420f1ddb90448b\igxelpicd64.dll
No symbol table info available.
#20 0x00007ffda03bf55b in glTexSubImage2D () from C:\WINDOWS\SYSTEM32\opengl32.dll
No symbol table info available.
#21 0x00007ffd708354a2 in gsk_gpu_upload_op_gl_command_with_area (op=op@entry=0x41f5d440, frame=frame@entry=0x37100700, image=image@entry=0x3d1efa80, area=area@entry=0x5fe240, draw_func=draw_func@entry=0x7ffd70835b13 <gsk_gpu_upload_cairo_op_draw>) at ../gsk/gpu/gskgpuuploadop.c:52
        gl_image = 0x3d1efa80
        format = GDK_MEMORY_B8G8R8A8_PREMULTIPLIED
        stride = 32
        bpp = 4
        data = 0x44629120 ""
        gl_format = 32993
        gl_type = 5121
#22 0x00007ffd7083558d in gsk_gpu_upload_op_gl_command (op=0x41f5d440, frame=0x37100700, image=0x3d1efa80, draw_func=draw_func@entry=0x7ffd70835b13 <gsk_gpu_upload_cairo_op_draw>) at ../gsk/gpu/gskgpuuploadop.c:82
No locals.
#23 0x00007ffd708355c3 in gsk_gpu_upload_cairo_op_gl_command (op=<optimized out>, frame=<optimized out>, state=<optimized out>) at ../gsk/gpu/gskgpuuploadop.c:478
        self = <optimized out>
#24 0x00007ffd70831102 in gsk_gpu_op_gl_command (op=op@entry=0x41f5d440, frame=frame@entry=0x37100700, state=state@entry=0x5fe300) at ../gsk/gpu/gskgpuop.c:49
No locals.
#25 0x00007ffd7081b40c in gsk_gl_frame_submit (frame=0x37100700, pass_type=<optimized out>, vertex_buffer=0x3249af60, globals_buffer=<optimized out>, op=0x41f5d440) at ../gsk/gpu/gskglframe.c:199
        self = 0x37100700
        state = {flip_y = 0, current_program = {op_class = 0x0, flags = 0, color_states = 0, variation = 0}, globals = 0x37100bc0, current_images = {0x0, 0x0}, current_samplers = {GSK_GPU_SAMPLER_N_SAMPLERS, GSK_GPU_SAMPLER_N_SAMPLERS}}
#26 0x00007ffd70824f5c in gsk_gpu_frame_submit (self=0x37100700, pass_type=GSK_RENDER_PASS_PRESENT) at ../gsk/gpu/gskgpuframe.c:769
        priv = 0x37100660
#27 0x00007ffd70825487 in gsk_gpu_frame_render (self=self@entry=0x37100700, timestamp=895689831370, target=target@entry=0xdd0f860, target_color_state=target_color_state@entry=0x7ffd7084d380 <gdk_default_color_states>, clip=clip@entry=0x3dba2180, node=node@entry=0x3e47eaf0, viewport=viewport@entry=0x5fe490, texture=texture@entry=0x0) at ../gsk/gpu/gskgpuframe.c:792
        pass_type = GSK_RENDER_PASS_PRESENT
#28 0x00007ffd708334d9 in gsk_gpu_renderer_render (renderer=<optimized out>, root=0x3e47eaf0, region=<optimized out>) at ../gsk/gpu/gskgpurenderer.c:435
        self = <optimized out>
        priv = 0xa6487a0
        frame = 0x37100700
        backbuffer = 0xdd0f860
        render_region = 0x3dba2180
        opaque_tmp = {origin = {x = 0, y = 0}, size = {width = 1920, height = 1032}}
        opaque = <optimized out>
        scale = 1
        depth = <optimized out>
#29 0x00007ffd707e99e6 in gsk_renderer_render (renderer=renderer@entry=0xa648810, root=root@entry=0x3e47eaf0, region=region@entry=0x1aa4f3a0) at ../gsk/gskrenderer.c:473
        priv = 0xa6487e0
        renderer_class = 0xa798d60
        clip = 0x3dda2220
        offload = 0x3da49620
        __func__ = "gsk_renderer_render"
#30 0x00007ffd70615ada in gtk_widget_render (widget=widget@entry=0x9eae8b0, surface=0xa6394f0, region=region@entry=0x1aa4f3a0) at ../gtk/gtkwidget.c:12118
        priv = 0x9eae760
        snapshot = 0x4d5075b0
        renderer = 0xa648810
        root = 0x3e47eaf0
        x = 0
        y = 0
        before_snapshot = 0
        before_render = 0
#31 0x00007ffd7061eca7 in surface_render (surface=<optimized out>, region=region@entry=0x1aa4f3a0, widget=widget@entry=0x9eae8b0) at ../gtk/gtkwindow.c:4826
No locals.
#32 0x00007ffd70770ce4 in _gdk_marshal_BOOLEAN__BOXEDv (closure=0x9fe6c80, return_value=0x5fe790, instance=<optimized out>, args=<optimized out>, marshal_data=0x0, n_params=1, param_types=0xa543f30) at gdk/gdkmarshalers.c:130
        cc = 0x9fe6c80
        data1 = <optimized out>
        data2 = 0x9eae8b0
        callback = 0x7ffd7061ec92 <surface_render>
        v_return = <optimized out>
        arg0 = 0x1aa4f3a0
        args_copy = 0x5fe9a0 "+Ú_"
        __func__ = "_gdk_marshal_BOOLEAN__BOXEDv"
#33 0x00007ffd8aed7add in _g_closure_invoke_va (closure=closure@entry=0x9fe6c80, return_value=return_value@entry=0x5fe790, instance=instance@entry=0xa6394f0, args=0x5fe998 "\240¾ñ\032", n_params=1, param_types=0xa543f30) at ../gobject/gclosure.c:896
        marshal = 0x7ffd70770c73 <_gdk_marshal_BOOLEAN__BOXEDv>
        marshal_data = 0x0
        in_marshal = 0
        real_closure = 0x9fe6c60
        __func__ = "_g_closure_invoke_va"
#34 0x00007ffd8aee90aa in signal_emit_valist_unlocked (instance=instance@entry=0xa6394f0, signal_id=signal_id@entry=259, detail=detail@entry=0, var_args=<optimized out>, var_args@entry=0x5fe998 "\240¾ñ\032") at ../gobject/gsignal.c:3438
        return_accu = 0x5fe790
        accu = {g_type = 20, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}}}
        emission = {next = 0x5feb80, instance = 0xa6394f0, ihint = {signal_id = 259, detail = 0, run_type = (G_SIGNAL_RUN_FIRST | G_SIGNAL_ACCUMULATOR_FIRST_RUN)}, state = EMISSION_RUN, chain_type = 63380384}
        instance_type = <optimized out>
        emission_return = {g_type = 20, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0,
 v_pointer = 0x0}}}
        rtype = 20
        static_scope = 0
        fastpath_handler = 0x14f354b0
        closure = 0x9fe6c80
        run_type = G_SIGNAL_RUN_FIRST
        hlist = <optimized out>
        l = <optimized out>
        fastpath = <optimized out>
        instance_and_params = <optimized out>
        param_values = <optimized out>
        node = <optimized out>
        i = <optimized out>
        __func__ = "signal_emit_valist_unlocked"
        node_copy = {signal_id = 259, itype = 63382288, name = 0x7ffd70acc984 <__func__.10+196> "render", destroyed = 0, flags = 2, n_params = 1, single_va_closure_is_valid = 1, single_va_closure_is_after = 0, param_types = 0xa543f30, return_type = 20, class_closure_bsa = 0x0, accumulator = 0xa544190, c_marshaller = 0x7ffd70770bb0 <_gdk_marshal_BOOLEAN__BOXED>, va_marshaller = 0x7ffd70770c73 <_gdk_marshal_BOOLEAN__BOXEDv>, emission_hooks = 0x0, single_va_closure = 0x1}
#35 0x00007ffd8aeed109 in g_signal_emit_valist (instance=0xa6394f0, signal_id=259, detail=0, var_args=0x5fe998 "\240¾ñ\032") at ../gobject/gsignal.c:3277
No locals.
#36 0x00007ffd8aeed13d in g_signal_emit (instance=0x1c0, instance@entry=0xa6394f0, signal_id=1164, detail=4277075694, detail@entry=0) at ../gobject/gsignal.c:3597
        var_args = 0x5fe998 "\240¾ñ\032"
#37 0x00007ffd707d0c6f in gdk_surface_paint_on_clock (clock=<optimized out>, data=0xa6394f0) at ../gdk/gdksurface.c:1458
        handled = 0
        surface = 0xa6394f0
        expose_region = 0x1aa4f3a0
        __func__ = "gdk_surface_paint_on_clock"
#38 0x00007ffd8aed93f4 in g_cclosure_marshal_VOID__VOID (closure=0xa518b20, return_value=<optimized out>, n_param_values=<optimized out>, param_values=<optimized out>, invocation_hint=0x5feb90, marshal_data=0x0) at ../gobject/gmarshal.c:117
        callback = 0x7ffd707d0bae <gdk_surface_paint_on_clock>
        cc = 0xa518b20
        data1 = 0xa519050
        data2 = 0x48c
        __func__ = "g_cclosure_marshal_VOID__VOID"
#39 0x00007ffd8aed78ff in g_closure_invoke (closure=0xa518b20, return_value=0x0, n_param_values=n_param_values@entry=1, param_values=param_values@entry=0x5fec30, invocation_hint=invocation_hint@entry=0x5feb90) at ../gobject/gclosure.c:833
        marshal = 0x7ffd8aed93c0 <g_cclosure_marshal_VOID__VOID>
        marshal_data = 0x0
        in_marshal = 0
        real_closure = 0xa518b00
        __func__ = "g_closure_invoke"
#40 0x00007ffd8aee8339 in signal_emit_unlocked_R (node=<optimized out>, node@entry=0x5fed10, detail=<optimized out>, detail@entry=0, instance=<optimized out>, instance@entry=0xa519050, emission_return=<optimized out>, emission_return@entry=0x0, instance_and_params=<optimized out>, instance_and_params@entry=0x5fec30) at ../gobject/gsignal.c:3902
        tmp = <optimized out>
        handler = 0xa518a90
        accumulator = <optimized out>
        emission = {next = 0x0, instance = 0xa519050, ihint = {signal_id = 268, detail = 0, run_type = (G_SIGNAL_RUN_FIRST | G_SIGNAL_ACCUMULATOR_FIRST_RUN)}, state = EMISSION_RUN, chain_type = 4}
        class_closure = <optimized out>
        hlist = <optimized out>
        handler_list = 0xa518a90
        return_accu = <optimized out>
        accu = {g_type = 0, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer =
 0x0}}}
        signal_id = <optimized out>
        max_sequential_handler_number = <optimized out>
        return_value_altered = <optimized out>
        n_params = <optimized out>
        __func__ = "signal_emit_unlocked_R"
#41 0x00007ffd8aee96d0 in signal_emit_valist_unlocked (instance=instance@entry=0xa519050, signal_id=signal_id@entry=268, detail=detail@entry=0, var_args=<optimized out>, var_args@entry=0x5fee68 "") at ../gobject/gsignal.c:3534
        instance_and_params = 0x5fec30
        param_values = 0x5fec48
        node = <optimized out>
        i = <optimized out>
        __func__ = "signal_emit_valist_unlocked"
        node_copy = {signal_id = 268, itype = 71074448, name = 0x7ffd70ab51e4 <gdk_button_event_info+292> "paint", destroyed = 0, flags = 2, n_params = 0, single_va_closure_is_valid = 1, single_va_closure_is_after = 0, param_types = 0x0, return_type = 4, class_closure_bsa = 0x0, accumulator = 0x0, c_marshaller = 0x7ffd8aed93c0 <g_cclosure_marshal_VOID__VOID>, va_marshaller = 0x7ffd8aed942e <g_cclosure_marshal_VOID__VOIDv>, emission_hooks = 0x0, single_va_closure = 0x1}
#42 0x00007ffd8aeed109 in g_signal_emit_valist (instance=0xa519050, signal_id=268, detail=0, var_args=0x5fee68 "") at ../gobject/gsignal.c:3277
No locals.
#43 0x00007ffd8aeed13d in g_signal_emit (instance=0x1c0, signal_id=1164, detail=4277075694) at ../gobject/gsignal.c:3597
        var_args = 0x5fee68 ""
#44 0x00007ffd707b9c39 in _gdk_frame_clock_emit_paint (frame_clock=0x1c0, frame_clock@entry=0xa519050) at ../gdk/gdkframeclock.c:735
        before = 0
#45 0x00007ffd707ba507 in gdk_frame_clock_paint_idle (data=0xa519050) at ../gdk/gdkframeclockidle.c:634
        clock = 0xa519050
        clock_idle = 0xa519050
        priv = 0xa518db0
        skip_to_resume_events = <optimized out>
        timings = 0x1b0ddd10
        before = 0
        __func__ = "gdk_frame_clock_paint_idle"
#46 0x00007ffd8a41b5d3 in g_timeout_dispatch (source=0x4e0eda70, callback=<optimized out>, user_data=<optimized out>) at ../glib/gmain.c:5111
        timeout_source = 0x4e0eda70
        again = <optimized out>
#47 0x00007ffd8a4186bb in g_main_dispatch (context=0x3c4f560) at ../glib/gmain.c:3398
        dispatch = 0x7ffd8a41b58b <g_timeout_dispatch>
        prev_source = 0x0
        begin_time_nsec = 0
        was_in_call = 0
        user_data = 0xa519050
        callback = 0x7ffd707ba357 <gdk_frame_clock_paint_idle>
        cb_funcs = 0x7ffd8a486470 <g_source_callback_funcs>
        cb_data = 0x41f9d9d0
        need_destroy = <optimized out>
        source = 0x4e0eda70
        current = 0x3c5ba00
        i = 0
        __func__ = "g_main_dispatch"
#48 0x00007ffd8a418770 in g_main_context_dispatch_unlocked (context=context@entry=0x3c4f560) at ../glib/gmain.c:4249
No locals.
#49 0x00007ffd8a41aa35 in g_main_context_iterate_unlocked (context=context@entry=0x3c4f560, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/gmain.c:4314
        max_priority = 120
        timeout_usec = 0
        some_ready = 1
        nfds = <optimized out>
        allocated_nfds = 3
        fds = 0x1563c270
        begin_time_nsec = 0
#50 0x00007ffd8a41af95 in g_main_context_iteration (context=context@entry=0x3c4f560, may_block=may_block@entry=1) at ../glib/gmain.c:4379
        retval = <optimized out>
#51 0x00007ffd81133285 in g_application_run (application=0x3c39eb0, argc=<optimized out>, argv=0x3ba84b0) at ../gio/gapplication.c:2715
        arguments = 0x3c40db0
        status = 0
        context = 0x3c4f560
        acquired_context = <optimized out>
        __func__ = "g_application_run"
#52 0x00007ffde0c85061 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#53 0x00007ffde0c84c5f in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#54 0x00007ffde0c84e32 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#55 0x00007ffdc43d2174 in ?? () from C:\TOOLS\msys64\ucrt64\lib\python3.12\site-packages\gi\_gi.cp312-mingw_x86_64_ucrt_gnu.pyd
No symbol table info available.
#56 0x00007ffdc43d4305 in ?? () from C:\TOOLS\msys64\ucrt64\lib\python3.12\site-packages\gi\_gi.cp312-mingw_x86_64_ucrt_gnu.pyd
No symbol table info available.
#57 0x00007ffd86d2a005 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#58 0x00007ffd86ddd16b in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#59 0x00007ffd86c86562 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#60 0x00007ffd86c84b1e in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#61 0x00007ffd86d634bd in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#62 0x00007ffd86d2939d in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#63 0x00007ffd86dd8c02 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#64 0x00007ffd86d2971e in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#65 0x00007ffd86cb07c8 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#66 0x00007ffd86cb043b in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#67 0x00007ff6bfd82a14 in ?? ()
No symbol table info available.
#68 0x00007ff6bfd81319 in ?? ()
No symbol table info available.
#69 0x00007ff6bfd81426 in ?? ()
No symbol table info available.
#70 0x00007ffde682e8d7 in KERNEL32!BaseThreadInitThunk () from C:\WINDOWS\System32\kernel32.dll
No symbol table info available.
#71 0x00007ffde7c7bf2c in ntdll!RtlUserThreadStart () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#72 0x0000000000000000 in ?? ()
No symbol table info available.

(no VM, just a native Windows11, with latest intel iris drivers)

If you feel like, try gathering more infos:

  • Open Visual Studio and select Continue without code
  • Launch the GTK app and maximize the window
  • In Visual Studio select Debug > Attach to process (Ctrl+Alt+P)
  • Press the pause button in the toolbar, or alternatively Debug > Break All
  • Open the Threads pane: Debug > Windows > Threads
  • Double click on the main thread
  • Open the Call Stack pane: Debug > Windows > Call Stack
  • Continue / pause until you get the callstack in glTexSubImage2D
  • Right click on a ntdll row and select Load Symbols. You can do this also for any system DLL.

You may also profile with Intel GPA:

https://www.intel.com/content/www/us/en/developer/tools/graphics-performance-analyzers/overview.html

Thanks!
I’ll try to get some debug data, but sadly it’s a work computer so I can’t install what I want on it…

Got a bt with gdb, hope it helps:

Summary
Thread 1 hit Breakpoint 2, 0x00007ffda03bf4e4 in glTexSubImage2D () from C:\WINDOWS\SYSTEM32\opengl32.dll
(gdb) bt full
#0  0x00007ffda03bf4e4 in glTexSubImage2D () from C:\WINDOWS\SYSTEM32\opengl32.dll
No symbol table info available.
#1  0x00007ffd6bd35582 in gsk_gpu_upload_op_gl_command_with_area (op=op@entry=0x3ab89d20, frame=frame@entry=0x15630d30, image=image@entry=0x3513cc60, area=area@entry=0x5fe240, draw_func=draw_func@entry=0x7ffd6bd35bf3 <gsk_gpu_upload_cairo_op_draw>)
    at ../gsk/gpu/gskgpuuploadop.c:52
        gl_image = 0x3513cc60
        format = GDK_MEMORY_B8G8R8A8_PREMULTIPLIED
        stride = 32
        bpp = 4
        data = 0x351fead0 ""
        gl_format = 32993
        gl_type = 5121
#2  0x00007ffd6bd3566d in gsk_gpu_upload_op_gl_command (op=0x3ab89d20, frame=0x15630d30, image=0x3513cc60, draw_func=draw_func@entry=0x7ffd6bd35bf3 <gsk_gpu_upload_cairo_op_draw>) at ../gsk/gpu/gskgpuuploadop.c:82
No locals.
#3  0x00007ffd6bd356a3 in gsk_gpu_upload_cairo_op_gl_command (op=<optimized out>, frame=<optimized out>, state=<optimized out>) at ../gsk/gpu/gskgpuuploadop.c:478
        self = <optimized out>
#4  0x00007ffd6bd311e2 in gsk_gpu_op_gl_command (op=op@entry=0x3ab89d20, frame=frame@entry=0x15630d30, state=state@entry=0x5fe300) at ../gsk/gpu/gskgpuop.c:49
No locals.
#5  0x00007ffd6bd1b4cc in gsk_gl_frame_submit (frame=0x15630d30, pass_type=<optimized out>, vertex_buffer=0x3a9871d0, globals_buffer=<optimized out>, op=0x3ab89d20) at ../gsk/gpu/gskglframe.c:199
        self = 0x15630d30
        state = {flip_y = 0, current_program = {op_class = 0x0, flags = 0, color_states = 0, variation = 0}, globals = 0x1562ffe0, current_images = {0x0, 0x0}, current_samplers = {GSK_GPU_SAMPLER_N_SAMPLERS, GSK_GPU_SAMPLER_N_SAMPLERS}}
#6  0x00007ffd6bd2501c in gsk_gpu_frame_submit (self=0x15630d30, pass_type=GSK_RENDER_PASS_PRESENT) at ../gsk/gpu/gskgpuframe.c:769
        priv = 0x15630c90
#7  0x00007ffd6bd25547 in gsk_gpu_frame_render (self=self@entry=0x15630d30, timestamp=1157621494872, target=target@entry=0x3b006810, target_color_state=target_color_state@entry=0x7ffd6bd4d380 <gdk_default_color_states>, clip=clip@entry=0x32720e70,
    node=node@entry=0x3a5dbaa0, viewport=viewport@entry=0x5fe490, texture=texture@entry=0x0) at ../gsk/gpu/gskgpuframe.c:792
        pass_type = GSK_RENDER_PASS_PRESENT
#8  0x00007ffd6bd335b9 in gsk_gpu_renderer_render (renderer=<optimized out>, root=0x3a5dbaa0, region=<optimized out>) at ../gsk/gpu/gskgpurenderer.c:435
        self = <optimized out>
        priv = 0xa2ed8c0
        frame = 0x15630d30
        backbuffer = 0x3b006810
        render_region = 0x32720e70
        opaque_tmp = {origin = {x = 0, y = 0}, size = {width = 1920, height = 1032}}
        opaque = <optimized out>
        scale = 1
        depth = <optimized out>
#9  0x00007ffd6bce9aa6 in gsk_renderer_render (renderer=renderer@entry=0xa2ed930, root=root@entry=0x3a5dbaa0, region=region@entry=0x351e1ce0) at ../gsk/gskrenderer.c:473
        priv = 0xa2ed900
        renderer_class = 0xa2d1590
        clip = 0x26f37840
        offload = 0x3468bf70
        __func__ = "gsk_renderer_render"
#10 0x00007ffd6bb15ada in gtk_widget_render (widget=widget@entry=0x9cbe870, surface=0xa349970, region=region@entry=0x351e1ce0) at ../gtk/gtkwidget.c:12118
        priv = 0x9cbe720
        snapshot = 0x346616b0
        renderer = 0xa2ed930
        root = 0x3a5dbaa0
        x = 0
        y = 0
        before_snapshot = 0
        before_render = 0
#11 0x00007ffd6bb1eca7 in surface_render (surface=<optimized out>, region=region@entry=0x351e1ce0, widget=widget@entry=0x9cbe870) at ../gtk/gtkwindow.c:4826
No locals.
#12 0x00007ffd6bc70ce4 in _gdk_marshal_BOOLEAN__BOXEDv (closure=0x14c98930, return_value=0x5fe790, instance=<optimized out>, args=<optimized out>, marshal_data=0x0, n_params=1, param_types=0xa4073f0) at gdk/gdkmarshalers.c:130
        cc = 0x14c98930
        data1 = <optimized out>
        data2 = 0x9cbe870
        callback = 0x7ffd6bb1ec92 <surface_render>
        v_return = <optimized out>
        arg0 = 0x351e1ce0
        args_copy = 0x5fe9a0 "╝Ú_"
        __func__ = "_gdk_marshal_BOOLEAN__BOXEDv"
#13 0x00007ffdac857add in _g_closure_invoke_va (closure=closure@entry=0x14c98930, return_value=return_value@entry=0x5fe790, instance=instance@entry=0xa349970, args=0x5fe998 "Ó\034\0365", n_params=1, param_types=0xa4073f0) at ../gobject/gclosure.c:896
        marshal = 0x7ffd6bc70c73 <_gdk_marshal_BOOLEAN__BOXEDv>
        marshal_data = 0x0
        in_marshal = 0
        real_closure = 0x14c98910
        __func__ = "_g_closure_invoke_va"
#14 0x00007ffdac8690aa in signal_emit_valist_unlocked (instance=instance@entry=0xa349970, signal_id=signal_id@entry=259, detail=detail@entry=0, var_args=<optimized out>, var_args@entry=0x5fe998 "Ó\034\0365") at ../gobject/gsignal.c:3438
        return_accu = 0x5fe790
        accu = {g_type = 20, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0,
--Type <RET> for more, q to quit, c to continue without paging--
              v_pointer = 0x0}}}
        emission = {next = 0x5feb80, instance = 0xa349970, ihint = {signal_id = 259, detail = 0, run_type = (G_SIGNAL_RUN_FIRST | G_SIGNAL_ACCUMULATOR_FIRST_RUN)}, state = EMISSION_RUN, chain_type = 69342096}
        instance_type = <optimized out>
        emission_return = {g_type = 20, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0,
              v_double = 0, v_pointer = 0x0}}}
        rtype = 20
        static_scope = 0
        fastpath_handler = 0x48d9c10
        closure = 0x14c98930
        run_type = G_SIGNAL_RUN_FIRST
        hlist = <optimized out>
        l = <optimized out>
        fastpath = <optimized out>
        instance_and_params = <optimized out>
        param_values = <optimized out>
        node = <optimized out>
        i = <optimized out>
        __func__ = "signal_emit_valist_unlocked"
        node_copy = {signal_id = 259, itype = 69343168, name = 0x7ffd6bfcc984 <__func__.10+196> "render", destroyed = 0, flags = 2, n_params = 1, single_va_closure_is_valid = 1, single_va_closure_is_after = 0, param_types = 0xa4073f0, return_type = 20,
          class_closure_bsa = 0x0, accumulator = 0xa2e31c0, c_marshaller = 0x7ffd6bc70bb0 <_gdk_marshal_BOOLEAN__BOXED>, va_marshaller = 0x7ffd6bc70c73 <_gdk_marshal_BOOLEAN__BOXEDv>, emission_hooks = 0x0, single_va_closure = 0x1}
#15 0x00007ffdac86d109 in g_signal_emit_valist (instance=0xa349970, signal_id=259, detail=0, var_args=0x5fe998 "Ó\034\0365") at ../gobject/gsignal.c:3277
No locals.
#16 0x00007ffdac86d13d in g_signal_emit (instance=0xde1, instance@entry=0xa349970, signal_id=0, detail=detail@entry=0) at ../gobject/gsignal.c:3597
        var_args = 0x5fe998 "Ó\034\0365"
#17 0x00007ffd6bcd0c6f in gdk_surface_paint_on_clock (clock=<optimized out>, data=0xa349970) at ../gdk/gdksurface.c:1458
        handled = 0
        surface = 0xa349970
        expose_region = 0x351e1ce0
        __func__ = "gdk_surface_paint_on_clock"
#18 0x00007ffdac8593f4 in g_cclosure_marshal_VOID__VOID (closure=0xa47dec0, return_value=<optimized out>, n_param_values=<optimized out>, param_values=<optimized out>, invocation_hint=0x5feb90, marshal_data=0x0) at ../gobject/gmarshal.c:117
        callback = 0x7ffd6bcd0bae <gdk_surface_paint_on_clock>
        cc = 0xa47dec0
        data1 = 0xa3f5c40
        data2 = 0x0
        __func__ = "g_cclosure_marshal_VOID__VOID"
#19 0x00007ffdac8578ff in g_closure_invoke (closure=0xa47dec0, return_value=0x0, n_param_values=n_param_values@entry=1, param_values=param_values@entry=0x5fec30, invocation_hint=invocation_hint@entry=0x5feb90) at ../gobject/gclosure.c:833
        marshal = 0x7ffdac8593c0 <g_cclosure_marshal_VOID__VOID>
        marshal_data = 0x0
        in_marshal = 0
        real_closure = 0xa47dea0
        __func__ = "g_closure_invoke"
#20 0x00007ffdac868339 in signal_emit_unlocked_R (node=<optimized out>, node@entry=0x5fed10, detail=<optimized out>, detail@entry=0, instance=<optimized out>, instance@entry=0xa3f5c40, emission_return=<optimized out>, emission_return@entry=0x0,
    instance_and_params=<optimized out>, instance_and_params@entry=0x5fec30) at ../gobject/gsignal.c:3902
        tmp = <optimized out>
        handler = 0xa47de30
        accumulator = <optimized out>
        emission = {next = 0x0, instance = 0xa3f5c40, ihint = {signal_id = 268, detail = 0, run_type = (G_SIGNAL_RUN_FIRST | G_SIGNAL_ACCUMULATOR_FIRST_RUN)}, state = EMISSION_RUN, chain_type = 4}
        class_closure = <optimized out>
        hlist = <optimized out>
        handler_list = 0xa47de30
        return_accu = <optimized out>
        accu = {g_type = 0, data = {{v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0, v_pointer = 0x0}, {v_int = 0, v_uint = 0, v_long = 0, v_ulong = 0, v_int64 = 0, v_uint64 = 0, v_float = 0, v_double = 0,
              v_pointer = 0x0}}}
        signal_id = <optimized out>
        max_sequential_handler_number = <optimized out>
        return_value_altered = <optimized out>
        n_params = <optimized out>
        __func__ = "signal_emit_unlocked_R"
#21 0x00007ffdac8696d0 in signal_emit_valist_unlocked (instance=instance@entry=0xa3f5c40, signal_id=signal_id@entry=268, detail=detail@entry=0, var_args=<optimized out>, var_args@entry=0x5fee68 "") at ../gobject/gsignal.c:3534
        instance_and_params = 0x5fec30
        param_values = 0x5fec48
        node = <optimized out>
        i = <optimized out>
        __func__ = "signal_emit_valist_unlocked"
        node_copy = {signal_id = 268, itype = 74231696, name = 0x7ffd6bfb51e4 <gdk_button_event_info+292> "paint", destroyed = 0, flags = 2, n_params = 0, single_va_closure_is_valid = 1, single_va_closure_is_after = 0, param_types = 0x0, return_type = 4,
          class_closure_bsa = 0x0, accumulator = 0x0, c_marshaller = 0x7ffdac8593c0 <g_cclosure_marshal_VOID__VOID>, va_marshaller = 0x7ffdac85942e <g_cclosure_marshal_VOID__VOIDv>, emission_hooks = 0x0, single_va_closure = 0x1}
#22 0x00007ffdac86d109 in g_signal_emit_valist (instance=0xa3f5c40, signal_id=268, detail=0, var_args=0x5fee68 "") at ../gobject/gsignal.c:3277
No locals.
#23 0x00007ffdac86d13d in g_signal_emit (instance=0xde1, signal_id=0, detail=0) at ../gobject/gsignal.c:3597
        var_args = 0x5fee68 ""
--Type <RET> for more, q to quit, c to continue without paging--
#24 0x00007ffd6bcb9c39 in _gdk_frame_clock_emit_paint (frame_clock=0xde1, frame_clock@entry=0xa3f5c40) at ../gdk/gdkframeclock.c:735
        before = 0
#25 0x00007ffd6bcba507 in gdk_frame_clock_paint_idle (data=0xa3f5c40) at ../gdk/gdkframeclockidle.c:634
        clock = 0xa3f5c40
        clock_idle = 0xa3f5c40
        priv = 0xa3f59a0
        skip_to_resume_events = <optimized out>
        timings = 0x1eabb730
        before = 0
        __func__ = "gdk_frame_clock_paint_idle"
#26 0x00007ffd806ab5d3 in g_timeout_dispatch (source=0x378975d0, callback=<optimized out>, user_data=<optimized out>) at ../glib/gmain.c:5111
        timeout_source = 0x378975d0
        again = <optimized out>
#27 0x00007ffd806a86bb in g_main_dispatch (context=0x4208630) at ../glib/gmain.c:3398
        dispatch = 0x7ffd806ab58b <g_timeout_dispatch>
        prev_source = 0x0
        begin_time_nsec = 0
        was_in_call = 0
        user_data = 0xa3f5c40
        callback = 0x7ffd6bcba357 <gdk_frame_clock_paint_idle>
        cb_funcs = 0x7ffd80716470 <g_source_callback_funcs>
        cb_data = 0x37563c50
        need_destroy = <optimized out>
        source = 0x378975d0
        current = 0x4203350
        i = 0
        __func__ = "g_main_dispatch"
#28 0x00007ffd806a8770 in g_main_context_dispatch_unlocked (context=context@entry=0x4208630) at ../glib/gmain.c:4249
No locals.
#29 0x00007ffd806aaa35 in g_main_context_iterate_unlocked (context=context@entry=0x4208630, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/gmain.c:4314
        max_priority = 120
        timeout_usec = 0
        some_ready = 1
        nfds = <optimized out>
        allocated_nfds = 3
        fds = 0x3ba8f50
        begin_time_nsec = 0
#30 0x00007ffd806aaf95 in g_main_context_iteration (context=context@entry=0x4208630, may_block=may_block@entry=1) at ../glib/gmain.c:4379
        retval = <optimized out>
#31 0x00007ffd78833285 in g_application_run (application=0x3b53950, argc=<optimized out>, argv=0x3a9d360) at ../gio/gapplication.c:2715
        arguments = 0x3ba8f50
        status = 0
        context = 0x4208630
        acquired_context = <optimized out>
        __func__ = "g_application_run"
#32 0x00007ffdda335061 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#33 0x00007ffdda334c5f in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#34 0x00007ffdda334e32 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libffi-8.dll
No symbol table info available.
#35 0x00007ffdda1e2174 in ?? () from C:\TOOLS\msys64\ucrt64\lib\python3.12\site-packages\gi\_gi.cp312-mingw_x86_64_ucrt_gnu.pyd
No symbol table info available.
#36 0x00007ffdda1e4305 in ?? () from C:\TOOLS\msys64\ucrt64\lib\python3.12\site-packages\gi\_gi.cp312-mingw_x86_64_ucrt_gnu.pyd
No symbol table info available.
#37 0x00007ffd86d2a005 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#38 0x00007ffd86ddd16b in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#39 0x00007ffd86c86562 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#40 0x00007ffd86c84b1e in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#41 0x00007ffd86d634bd in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#42 0x00007ffd86d2939d in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#43 0x00007ffd86dd8c02 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#44 0x00007ffd86d2971e in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
--Type <RET> for more, q to quit, c to continue without paging--
No symbol table info available.
#45 0x00007ffd86cb07c8 in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#46 0x00007ffd86cb043b in ?? () from C:\TOOLS\msys64\ucrt64\bin\libpython3.12.dll
No symbol table info available.
#47 0x00007ff6ef9c2a14 in ?? ()
No symbol table info available.
#48 0x00007ff6ef9c1319 in ?? ()
No symbol table info available.
#49 0x00007ff6ef9c1426 in ?? ()
No symbol table info available.
#50 0x00007ffde682e8d7 in KERNEL32!BaseThreadInitThunk () from C:\WINDOWS\System32\kernel32.dll
No symbol table info available.
#51 0x00007ffde7c7bf2c in ntdll!RtlUserThreadStart () from C:\WINDOWS\SYSTEM32\ntdll.dll
No symbol table info available.
#52 0x0000000000000000 in ?? ()
No symbol table info available.

No problem, we’ll eventually find a way to reproduce :wink:

Well, getting a stacktrace with Visual Studio helps determining what functions are called in NTDLL. We see RtlAllocateHeap etc, but that’s not the real stacktrace. GDB can only resolve names from the set of NTDLL exported functions, while Visual Studio knows internal function names (thanks to the symbol server). But let’s skip that, it’s not important right now

BTW, can you reproduce with GSK_DEBUG=full-redraw gtk4-widget-factory? Can you also check the framerate of GSK_DEBUG=full-redraw GDK_DEBUG=no-vsync gtk4-widget-factory?

I’ll make some test on an Intel laptop

GSK_DEBUG=full-redraw GSK_RENDERER=ngl gtk4-widget-factory
60 fps, idle callback works :white_check_mark:

GSK_DEBUG=full-redraw GDK_DEBUG=no-vsync GSK_RENDERER=ngl gtk4-widget-factory
350 fps, idle callback not called :x:

GSK_DEBUG=full-redraw GSK_RENDERER=vulkan gtk4-widget-factory
60 fps, idle callback works :white_check_mark:

GSK_DEBUG=full-redraw GDK_DEBUG=no-vsync GSK_RENDERER=vulkan gtk4-widget-factory
980 fps, idle callback not called :x:

1 Like