Displaying help takes a long time

[iSchluff]

Bringing up the help takes about ten seconds for me.

The following is logged by Talon:

2022-01-25 13:49:10 WARNING [watchdog] "user.cursorless-talon.src.cheatsheet.cheat_sheet.draw" @2.0s
   13:                                     talon/canvas.py:17 |
   12:                                     talon/canvas.py:164|
   11:                         talon/scripting/dispatch.py:144|
   10:                         talon/scripting/dispatch.py:135|
    9:                             talon/scripting/rctx.py:233| # 'draw' user.cursorless-talon.src.cheatsheet.cheat_sheet:draw()
    8: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:123| self.draw_section(canvas, "Special mar..
    7: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:161| self.draw_items(canvas, items)
    6: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:236| self.draw_dict(canvas, items)
    5: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:254| self.draw_value(canvas, text)
    4: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:283| canvas.paint.typeface = text_font
    3:                                 talon/skia/paint.py:189|
    2:                                  talon/skia/font.py:79 |
    1:                              talon/skia/typeface.py:44 |
2022-01-25 13:49:13 WARNING [watchdog] "user.cursorless-talon.src.cheatsheet.cheat_sheet.draw" @2.0s
   13:                                     talon/canvas.py:17 |
   12:                                     talon/canvas.py:164|
   11:                         talon/scripting/dispatch.py:144|
   10:                         talon/scripting/dispatch.py:135|
    9:                             talon/scripting/rctx.py:233| # 'draw' user.cursorless-talon.src.cheatsheet.cheat_sheet:draw()
    8: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:123| self.draw_section(canvas, "Special mar..
    7: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:161| self.draw_items(canvas, items)
    6: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:236| self.draw_dict(canvas, items)
    5: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:254| self.draw_value(canvas, text)
    4: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:283| canvas.paint.typeface = text_font
    3:                                 talon/skia/paint.py:189|
    2:                                  talon/skia/font.py:79 |
    1:                              talon/skia/typeface.py:44 |
2022-01-25 13:49:15 WARNING [watchdog] "user.cursorless-talon.src.cheatsheet.cheat_sheet.draw" @2.0s
   13:                                     talon/canvas.py:17 |
   12:                                     talon/canvas.py:164|
   11:                         talon/scripting/dispatch.py:144|
   10:                         talon/scripting/dispatch.py:135|
    9:                             talon/scripting/rctx.py:233| # 'draw' user.cursorless-talon.src.cheatsheet.cheat_sheet:draw()
    8: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:111| self.draw_section(
    7: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:161| self.draw_items(canvas, items)
    6: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:236| self.draw_dict(canvas, items)
    5: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:254| self.draw_value(canvas, text)
    4: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:283| canvas.paint.typeface = text_font
    3:                                 talon/skia/paint.py:189|
    2:                                  talon/skia/font.py:79 |
    1:                              talon/skia/typeface.py:44 |
2022-01-25 13:49:17 WARNING [watchdog] "user.cursorless-talon.src.cheatsheet.cheat_sheet.draw" @2.0s
   13:                                     talon/canvas.py:17 |
   12:                                     talon/canvas.py:164|
   11:                         talon/scripting/dispatch.py:144|
   10:                         talon/scripting/dispatch.py:135|
    9:                             talon/scripting/rctx.py:233| # 'draw' user.cursorless-talon.src.cheatsheet.cheat_sheet:draw()
    8: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:123| self.draw_section(canvas, "Special mar..
    7: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:161| self.draw_items(canvas, items)
    6: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:236| self.draw_dict(canvas, items)
    5: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:254| self.draw_value(canvas, text)
    4: user/cursorless-talon/src/cheatsheet/cheat_sheet.py:283| canvas.paint.typeface = text_font
    3:                                 talon/skia/paint.py:189|
    2:                                  talon/skia/font.py:79 |
    1:                              talon/skia/typeface.py:44 |

I am running talon v0.2.0-305-g968a (305)
cursorless-talon 0.25.0
and knausj_talon commit ea9b2d767be59cfccb5e6831874f2173114cd6bb
on Linux.

Greetings, Anton

[pokey]

@lunixbochs @AndreasArvidsson any idea why we'd be getting watchdogs with a stacktrace like the above? If I'm reading the trace correctly, it's happening while setting the font? Seems odd...

[lunixbochs]

As this is on Linux it might be nice to get a strace -tt -eopenat,stat or perf trace output for the period the watchdog is active. We're probably stalled on something Skia is doing, which might be stalled in the GPU driver or filesystem, and I have no idea what exactly without some kind of trace.

Also are you setting the font multiple times? Those watchdogs are each for 2s. Maybe it will improve if you only set it once per draw?

[pokey]

Also are you setting the font multiple times? Those watchdogs are each for 2s. Maybe it will improve if you only set it once per draw?

Ah yes we do set it repeatedly, actually to the same thing. Didn't realise setting font would have such a performance penalty. We could reduce the number of times we set it by a bunch. That's fairly low-hanging fruit

[lunixbochs]

Would love to get a trace to know why it's slow, I assume it needs to go actually find and load the font from disk every time on that system for some reason.

[pokey]

As this is on Linux it might be nice to get a strace -tt -eopenat,stat or perf trace output for the period the watchdog is active. We're probably stalled on something Skia is doing, which might be stalled in the GPU driver or filesystem, and I have no idea what exactly without some kind of trace.

@iSchluff any chance you'd be able to post this output to help us debug this one?

[iSchluff]

Sorry for the delay, haven't been keeping up with GitHub so much lately ^^'
strace.txt
Apparently its locking a lot and checking the permissions of the fonts, but no open/read.

perf trace -s
syscall summary.txt

[pokey]

thanks @iSchluff! @lunixbochs does the above help?