GNOME Bugzilla – Bug 743267
Caribou does 100-130 syscalls for each keypress
Last modified: 2021-05-25 17:46:30 UTC
Created attachment 295048 [details] Strace of single key press I do not think I use actually caribou, but my Fedora 21 install starts it running in the background. First I noticed in top when it very occasionally can used 5% of cpu in short spikes (very rarely). The bug I'm reporting is that according to strace caribou does 100-130 syscalls for each keypress. And according to ltrace caribou does 41 library calls for each keypress (8 atspi, 9 dbus, 24 glib).
Created attachment 295049 [details] ltrace of single key press Missing from the bug was that Fedora 21 caribou version is currently 0.4.16
Thanks for the analysis. Would you mind trying a test package? http://koji.fedoraproject.org/koji/taskinfo?taskID=8685709 where I added a patch to avoid redundant D-Bus calls for caret movement, as I see atspi_text_get_character_extents in your ltrace log and also observed that gnome-terminal emits caret movement signal many times. (for the undesired caribou invocation, see bug 741243)
Still same amount of ltrace/strace log lines with your koji build. My test is to just run in gnome terminal: # ltrace -t -p $(pgrep caribou) -o /tmp/ltrace.out And then press ctrl-c (pressing ctrl seems to count as one key press). If I press keys multiple times with 2 second delay between them in the terminal before terminating then the amount of log lines is (almost) multiple of the number of lines of single key press.
Created attachment 295140 [details] test script Thanks for the info. By increasing strsize of strace, I see "org.a11y.atspi.Accessible.GetRole" is called very often. It can also be observed with the attached track-caret.py: $ ./track-caret.py (...on another terminal...) $ strace -p `pgrep track-caret` -e trace=sendmsg -s1024 (...type keys to move caret...) sendmsg(6, {msg_name(0)=NULL, msg_iov(2)=[{"...GetRole\0", 128}, {"", 0}], ... sendmsg(6, {msg_name(0)=NULL, msg_iov(2)=[{"...GetRole\0", 128}, {"", 0}], ... ... I thought that role is cached in libatspi and isn't queried via D-Bus so often. Mike: is this a bug or usage problem?
Created attachment 296002 [details] [review] daemon: Use Atspi's main loop instead of GLib's To enable D-Bus property caching in libatspi, the client must call atspi_event_main. -- OK, it appears to be a usage problem. Since the caribou daemon has two aspects (as an AT-SPI service and a D-Bus service), I used GLib's mainloop instead of at-spi2-core's. In that case, D-Bus property caching is disabled by default: https://git.gnome.org/browse/at-spi2-core/tree/atspi/atspi-accessible.c#n1724 This patch should fix this. Mikko, could you try another scratch build? http://koji.fedoraproject.org/koji/taskinfo?taskID=8806535
Unfortunately even the latest scratch build still works identically. I installed it and rebooted before testing. Can you not reproduce the behavior yourself?
Well, I did, and confirmed that the most of the sendmsg calls are gone. Did you measure the number of calls before and after installing the package? I did: $ strace -p `pgrep caribou` -e trace=sendmsg -s 1024 -o log and type a key 3 times. The results are: Before: $ wc -l log 150 log After: $ wc -l log 14 log Since the daemon also reports caret position via D-Bus and the position changes when you type a key, I think other D-Bus calls are inevitable. Or, are you seeing other syscalls than sendmsg now?
GNOME is going to shut down bugzilla.gnome.org in favor of gitlab.gnome.org. As part of that, we are mass-closing older open tickets in bugzilla.gnome.org which have not seen updates for a longer time (resources are unfortunately quite limited so not every ticket can get handled). If you can still reproduce the situation described in this ticket in a recent and supported software version, then please follow https://wiki.gnome.org/GettingInTouch/BugReportingGuidelines and create a new enhancement request ticket at https://gitlab.gnome.org/GNOME/caribou/-/issues/ Thank you for your understanding and your help.