GNOME Bugzilla – Bug 707218
orca becomes non-responsive when arrowing very quickly through large a GtkTreeView
Last modified: 2013-09-06 19:41:00 UTC
I can't get orca to work reliably. This happens on many apps. I reproduce a hanging issue on orca preferences. 1. Start orca 2. Switch to accessible app, press Insert+Space to enter the preferences 3. Switch off mouse tracking to make things easier 4. Go to "Key bindings" tab 5. Click the first action in the table: it's being spoken, one may stop it with Ctrl, so far so good. 6. Try moving by one item at a time using keyboard (arrow down) - still ok 7. Try moving rapidly. Things stop working well and finally orca seems to be totally hanged. What worries me before hanging is the behaviour when I try to move by 2 entries. Both entries are spoken completely without ability to stop it. I would expect that the second key down stops speaking and moves immediately to the next item. Both issues are not 100% reproducable, but at most several attempts are enough. I thought I'd take part in orca development, but at the moment I'm stuck, because I can't get it to work at all. Maybe you can help me. Point me what to check, say what's the expected behaviour, test if my problem is reproducable on your machines. Orca version: many tried, most attempts made on git checkout from 2013-08-31. Operating system: Debian jessie (unstable). Window manager: openbox.
I cannot reproduce this. And I even pressed and held down the Down Arrow so that it really jumped. I did see some occasions where Orca began presenting earlier items (sort of a stuttering sound of the speech sythesizer). This was due to Orca getting an accessible/at-spi2 event for an earlier selection change, beginning to present it, and then getting a newer accessible/at-spi2 selection change event which told it the former was no longer valid. Having said that, they were nothing like you described, and most certainly not a hang. I'm also surprised that you're experiencing any kind of hang as the at-spi2 timeouts designed to prevent hangs, well, prevent hangs. ;) Are you also using the current (or a quite recent) version of at-spi2-core, at-spi2-atk, atk, and gtk+? Also, are you sure that the older/system version of at-spi2's registry are not running at the same time (or instead of) the new one? Lastly, getting a full debug.out as described here might shed some light on things. I say "might" because if your development environment is somehow borked, Orca's debugging output won't clearly point that out. [1] https://wiki.gnome.org/Orca/Debugging
Hello Joanmarie! You made me happy treating my problem seriously :) Please tell if these libraries are ok. I believe they all come from jessie debian release. Package: at-spi2-core Version: 2.9.5-1 Package: gir1.2-atspi-2.0 Version: 2.9.5-1 Package: libatspi2.0-0 Version: 2.9.5-1 Package: libatspi2.0-dev Version: 2.9.5-1 Package: libgtk-3-0 Version: 3.8.2-3 Package: python-pyatspi Version: 2.9.3+dfsg-1 Package: python3-pyatspi Version: 2.9.3+dfsg-1 I attach the debug output. Until getting to Insert+2, working fine. Then I did 3 fast key downs, which resulted in Insert+4 being spoken. Then big delay came. After about 10 seconds I heard the Insert+5 item and quit orca then. Don't know if attaching "hanged" state makes sense, as I need to kill orca in such case. I guess the big delay case should help us solve the problem. After you rule out problem with my libraries, I'll start to debug the code on my own. Thanks Jarek
Created attachment 253769 [details] log with misc actions, I suggest to delete it
And the packages containing atk: Package: gir1.2-atk-1.0 Version: 2.8.0-2 Package: libatk-adaptor Version: 2.9.5-1 Package: libatk-bridge2.0-0 Version: 2.9.5-1 Package: libatk-bridge2.0-dev Version: 2.9.5-1 Package: libatk-wrapper-java Version: 0.30.4-4 Package: libatk-wrapper-java-jni Version: 0.30.4-4 Package: libatk1.0-0 Version: 2.8.0-2 Package: libatk1.0-data Version: 2.8.0-2 Package: libatk1.0-dev Version: 2.8.0-2 Package: libatkmm-1.6-1 Version: 2.22.7-2 Package: libatkmm-1.6-dev Version: 2.22.7-2
(In reply to comment #2) > Please tell if these libraries are ok. I believe they all come from jessie > debian release. Cool. Nice to see debian unstable this caught up. :) Yeah, those should be fine. > I attach the debug output. Until getting to Insert+2, working fine. Then I did > 3 fast key downs, which resulted in Insert+4 being spoken. Then big delay came. > After about 10 seconds I heard the Insert+5 item and quit orca then. From your debug.out, it seems that Orca sent quite a bit more to speech-dispatcher for speaking: ===================================== $ grep -r "SPEECH OUTPUT" debug-2013-09-01-19:43:43.out SPEECH OUTPUT: 'Screen reader on.' voice=hyperlink SPEECH OUTPUT: 'Run command - gedit' SPEECH OUTPUT: 'Command to run text.' SPEECH OUTPUT: 'Screen Reader Preferences' SPEECH OUTPUT: 'General page tab.' SPEECH OUTPUT: 'Key Bindings page tab.' SPEECH OUTPUT: 'Function column header Go to bookmark. Insert+1 Modified check box not checked.' SPEECH OUTPUT: 'tree level 2' SPEECH OUTPUT: 'Go to bookmark. Insert+2 Modified check box not checked.' SPEECH OUTPUT: 'Go to bookmark. Insert+3 Modified check box not checked.' SPEECH OUTPUT: 'not selected' SPEECH OUTPUT: 'Go to bookmark. Insert+4 Modified check box not checked.' SPEECH OUTPUT: 'Go to bookmark. Insert+5 Modified check box not checked.' SPEECH OUTPUT: 'not selected' SPEECH OUTPUT: 'Go to bookmark. Insert+6 Modified check box not checked.' SPEECH OUTPUT: 'Add bookmark. Insert+Alt_L+1 Modified check box not checked.' SPEECH OUTPUT: 'not selected' SPEECH OUTPUT: 'Add bookmark. Insert+Alt_L+2 Modified check box not checked.' SPEECH OUTPUT: 'Add bookmark. Insert+Alt_L+3 Modified check box not checked.' SPEECH OUTPUT: 'not selected' SPEECH OUTPUT: 'Add bookmark. Insert+Alt_L+4 Modified check box not checked.' SPEECH OUTPUT: 'Go to bookmark. Insert+1 Modified check box not checked.' SPEECH OUTPUT: 'Go to bookmark. Insert+2 Modified check box not checked.' ===================================== I wonder if the problem is something in speech-dispatcher.... Is that something you could dig deeper into? In the meantime, I will see if I can catch and stop the full processing of those events. Your "hang" aside, the stuttering problem is annoying. > Don't know if attaching "hanged" state makes sense From what you've shown me thus far, it does not. Orca is continuing to work its way through all the accessibility events it gets from at-spi2 and continuing to send strings to speech-dispatcher to be spoken. To determine if Orca is really hanged, you could try a functional test: What happens if you wait (and wait, and wait. Go make a sandwich. ;) )? BTW, I'm still taking your reported problem seriously; just trying to determine if we really have a hang as opposed to a horrible bottleneck caused by an accessible event flood and/or a bug in speech-dispatcher. Thanks!!
Lowering it from critical to major as per the Bugzilla definitions of each: Critical: Crashes, causes loss of data, or is a severe memory leak Major: Major loss of functionality - menu item broken, data output extremely incorrect, or otherwise difficult/useless to use.
I am sorry. I sent the wrong debug file. Now that I know how to grep them for OUTPUT I verified the thing more carefully. Attaching the log for going to "5", the one I mentioned first. I attach also another log. Where I went to "3" with single steps. Then tried 3 times down. Orca stopped at "4", speaking it all. Then a few seconds delay and I heard "6". Then quit. I think you don't have to put much work on it. It's time for me to have a closer look at the code. Anyway if you need more info, I'll cooperate. Will do more testing on a hanged case too, but not today. Cheers Jarek
Created attachment 253777 [details] going from 2 to 5
I just committed a change to Orca that treats object:active-descendant-changed events as potential "event flood" suspects. [1] You should now find that when you perform the test you did when generating the previous debug.out, you have a lot fewer "SPEECH OUTPUT" lines as a result. Hopefully that change is sufficient to make the bug go away. Please let me know. Thanks again! [1] https://git.gnome.org/browse/orca/commit/?id=9b51a3e24991c67bdeb2b0cc9439f0606f2c05e4
Created attachment 253778 [details] log for going from 3 to 6
(In reply to comment #7) > I think you don't have to put much work on it. It's time for me to have a > closer look at the code. Before you do that, mind retesting the latest master? We're getting awfully close to code freeze for this cycle. Thanks!
git pull; make; make install - no visible influence on the issue. Today's change visible in git log. What I can add: if I wait for orca to start reading the current item and only then move farther, that works ok. Only pressing quickly cause the problem. Probably this "quickly" means some timing issue, absent on some machines. Mine is quite old 3.2GHz Celeron. Not much memory, 2GB.
Interesting.... I'll see about setting up a virtual machine that has similar conditions. For now, un-NEEDINFOing this. Thanks again for the report and testing!
Where is she gone? Attached a new log where it's clearly visible where the lag is located. It says nothing to me yet, but reporting on-line.
Created attachment 254000 [details] log for comment "Where is she gone?"
Based on your log, I'm becoming more and more convinced this is not an Orca bug. When a full debug.out is generated, it logs a ton. Here is where the delay is taking place: [1378229789.4095292] SPEECH OUTPUT: 'Go to bookmark. Insert+1 Modified check box not checked.' [1378229789.418907] TOTAL PROCESSING TIME: 0.2519 [1378229789.4189646] ^^^^^ PROCESS OBJECT EVENT object:active-descendant-changed ^^^^^ [1378229813.4889812] DEQUEUED OBJECT:TEXT-CHANGED:INSERT <---------- Seems 24 seconds passed between handling events. Orca immediately processes events -- unless something is preventing it from doing so. I think something outside of Orca is preventing it from doing so. Dunno what.... Transfering this to AT-SPI2 to be evaluated by Mike. Maybe he has an idea.
Yeah, it is definitely a regression in AT-SPI 2.9. I probably introduced it when trying to fix some other deadlocks with gnome-shell. I'm struggling with it at the moment. It seems that key events sent by orca aren't being processed by orca, or the replies to them aren't being forwarded to the registry daemon, or something similar, so Orca freezes until the call eventually times out. API, I'm CCing you because Joanie asked me to.
Next debugging day conclusions: It could still be orca problem. Note that event id=65507 is mentioned in the log 24 seconds before. Orca got it before, it is put in the queue. Then probably idle handler goes off and there's no thread to dequeue it. But this is speculation already. I need more time to determine it. Please try to reproduce after changing idle handler priority: self._gidleId = GLib.idle_add(self._dequeue, priority=0) The default is 200, down to -100 are valid values. For me lowering the priority made the issue reproduce more often. Priority values here: https://developer.gnome.org/glibmm/2.34/namespaceGlib.html
Created attachment 254147 [details] Orca-free, simple way to reproduce this bug I was able to reproduce the bug in Orca by upgrading at-spi2-core, at-spi2-atk, and pyatspi2. Having done so, I came up with the dead-simple test case I have attached. To reproduce the bug: 0. Do not launch Orca (just to prove this is not an Orca issue) 1. Launch the attached test case in a terminal. 2. Press and hold down the Right Arrow. Expected results: No matter how long you hold down the Right Arrow, the GtkNotebook page tabs would switch and your session would not freeze. Actual results: After cycling through the page tabs once or twice, your session freezes. Take a short break. After 20 or so seconds, the page tab will switch and things go back to normal. I see this bug with the current unstable at-spi2; I do not see this bug with the current stable at-spi2.
that commit 4ed79c in at-spi2-core and commit 548578 in at-spi2-atk should help. If other people want to test them, then that would be helpful.
Created attachment 254211 [details] More dramatic, easier to reproduce, Orca-free way to reproduce this bug Mike, I'm re-setting up my jhbuild environment, so I have not yet been able to test if the aforementioned commits fix the problem found in the opening report. In the meantime, what I have just attached has completely locked up my session with AT-SPI2 2.9.91. With AT-SPI2 2.8, there is no such lockup. Steps to reproduce are pretty much the same as the previous test case: 0. Do NOT start Orca 1. Start the attached in gnome-terminal 2. Press and hold Down Arrow until you jump to the bottom 3. Press and hold Up Arrow until you get to the top 4. You may need to repeat steps 2 and 3. I don't. Expected results: Your GNOME session would not freeze, events would continue to be printed in the terminal. Actual results: Your GNOME session completely freezes (mine has been frozen for 5 minutes now), and of course events stop being printed in the terminal. I can still get to a virtual console, however. Having said all that, once I have a full jhbuild environment, I'll try with at-spi2 from master. If the problem doesn't happen there, then I think we can safely call this fixed.
Created attachment 254212 [details] backtrace taken when test case freezes Still waiting for jhbuild to finish doing its thang, but should anyone be curious, here's the backtrace when using AT-SPI2 2.9.91.
Well, the good news is that I have verified that my latest test case is fixed for at-spi2-core master. The bad news is that, in my jhbuild environment, Orca is still freezing. I'll dig some more.... *sighs*
Created attachment 254215 [details] backtrace taken when orca freezes Comparing Thread 1 from each freeze, when Orca freezes, send_and_allow_reentry() is getting called.
Just pushed a fix to at-spi2-core (150f70). This seems to finally be fixed now. Please re-open if the bug is still present in some form with an up-to-date at-spi2-core and at-spi2-atk.
I compiled and installed the latest version of at-spi2-atk and at-spi2-core from git and seems that the problem was fiexed. It was almost impossible to navigate the tab keybinding preferences in the orca, but now everything works correctly in my arch box with gnome-3.8.
(In reply to comment #26) > I compiled and installed the latest version of at-spi2-atk and at-spi2-core > from git and seems that the problem was fiexed. > > It was almost impossible to navigate the tab keybinding preferences in the > orca, but now everything works correctly in my arch box with gnome-3.8. FWIW, I also made a test with the latest version of at-spi2-atk and at-spi2-core and gnome-shell with the magnifier and all is working. Mentioning because as far as I understood IRC conversations, this problem started after some changes to fix the reentrancy issues on gnome-shell using at-spi. In summary: no regressions detected.
The reporter confirms. After installing binaries from repository and removing libatk-bridge-2.0 and libatspi from /usr/lib - orca no longer hangs on preferences. If possible, please let me know when I can get back to debian package libraries. That is when they are updated in debian jessie.