After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 673556 - The new AT-SPI2 timeout errors need to be handled
The new AT-SPI2 timeout errors need to be handled
Status: RESOLVED FIXED
Product: orca
Classification: Applications
Component: general
unspecified
Other Linux
: Normal normal
: ---
Assigned To: Orca Maintainers
Orca Maintainers
Depends on:
Blocks:
 
 
Reported: 2012-04-05 08:00 UTC by Hammer Attila
Modified: 2012-05-01 13:36 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
Debug file with possible showing why happening this issue (61.96 KB, application/zip)
2012-04-05 08:02 UTC, Hammer Attila
Details
Debug file with show the master version of qt-at-spi produced test result (40.00 KB, application/zip)
2012-04-10 06:24 UTC, Hammer Attila
Details
Fresh debug file with the latest commits result (38.39 KB, application/zip)
2012-04-10 12:39 UTC, Hammer Attila
Details
Fresh result (694.28 KB, application/octet-stream)
2012-04-10 13:09 UTC, Hammer Attila
Details
Two debug file with Thunderbird related (37.55 KB, application/zip)
2012-04-10 14:34 UTC, Hammer Attila
Details
Fresh debug.out file with yesterday latest commits (15.60 KB, application/zip)
2012-04-11 04:57 UTC, Hammer Attila
Details
Thunderbird related debug file after at-spi2-core update (21.40 KB, application/zip)
2012-04-11 05:34 UTC, Hammer Attila
Details
A process appears to be hung error containing debug.out when Orca want mapping script for Thunderbird (16.49 KB, application/zip)
2012-04-11 06:17 UTC, Hammer Attila
Details
A process apper be chunk traceback when I tested Pidgin (70.99 KB, application/zip)
2012-04-11 14:51 UTC, Hammer Attila
Details
Fresh debug file after I applied Mike patches and updated Orca with latest commits (16.37 KB, application/zip)
2012-04-12 06:54 UTC, Hammer Attila
Details
Fresh debug file with Thunderbird related (15.31 KB, application/zip)
2012-04-13 05:03 UTC, Hammer Attila
Details
I think this debug.out file producing right result (187.15 KB, text/plain)
2012-04-13 13:46 UTC, Hammer Attila
Details

Description Hammer Attila 2012-04-05 08:00:50 UTC
Dear Developers,

Now happened me an interesting problem with Skype:
I logged in, and short time later my friend with I would like talking in skype logged in. I try search my friend contact in the Skype contact tree, but I not founded.
I see two echo/soundtest service contact. When I go to top of the contact list and choosed rename menu item, in edit box I see my friend contact name the edit box. So unfortunately Orca sends wrong output before rename menu item choose for speech and braille.
When I restarted Orca, all contacts Orca spokening again right. I see right my friend contact name before echo/soundtest service.
Hopefuly possible fixing this issue with Orca level or the qt-at-spi bridge.

When I experienced this issue, I maked an Orca debug.out file, sending with attachment.
Debug file not showing any traceback error messages.

Attila
Comment 1 Hammer Attila 2012-04-05 08:02:58 UTC
Created attachment 211357 [details]
Debug file with possible showing why happening this issue

I sending debug.out file with zip compressed format.

Attila
Comment 2 Hammer Attila 2012-04-05 08:04:55 UTC
In Ubuntu 12.04 I using Orca master version, and qt-at-spi 0.2.0-0ubuntu1 packaged version.

Attila

Attila
Comment 3 Joanmarie Diggs (IRC: joanie) 2012-04-05 11:24:12 UTC
I'm guessing this is a qt-at-spi bug. Could you please report it there and include the response here? Thanks!
Comment 4 Hammer Attila 2012-04-05 11:33:24 UTC
Of course, I reporting this issue.
I not known now what the bug tracker with qt-at-spi project, but I will be searching in my Orca List archives.

Attila
Comment 5 Hammer Attila 2012-04-05 11:53:20 UTC
Hy Joanie,

Unfortunately I not have lucki. The https://bugreports.qt.nokia.com page not possible to present my Firefox 11.
Can you known an another bugreport page for qt-at-spi bridge?
I only see the popupped window with a leave the page button.

Attila
Comment 6 Joanmarie Diggs (IRC: joanie) 2012-04-05 11:55:06 UTC
Why not report it on the kde accessibility list?
kde-accessibility@kde.org
https://mail.kde.org/mailman/listinfo/kde-accessibility
Comment 7 Hammer Attila 2012-04-05 13:57:32 UTC
Frederik answered following in KDE Accessibility List:
"This is a know and bad issue in qt-at-spi. The problem is that the Gnome
stack caches every accessible to the last detail.
So currently Orca and the at-spi2 libs keep track of every information
they ever get. Even marking trees as "manages descendants" which should
prevent this behavior does not seem to help.
Now the qt-at-spi bridge is not updating the tree in the way expected
since that is quite tricky and I'm still not sure how to do it properly
in an elegant way.
This leads to the Gnome side thinking that the tree is in some state it
had before. That is why restarting Orca helps.
I am convinced that sending updates for trees all the time to enable
proper caching is not a good idea and one reason why the performance of
at-spi 2 is frowned upon. That is why I refuse to even try to implement
it the same way as atk does. I don't have a good solution at the moment
though.

Frederik"
What possible doing this situation?

Attila
Comment 8 Joanmarie Diggs (IRC: joanie) 2012-04-05 14:02:24 UTC
Thanks Attila! Orca is passing along what it gets from AT-SPI2, so I'm going to move this bug to AT-SPI2 and see if Mike has any brilliant ideas.
Comment 9 Hammer Attila 2012-04-10 06:24:43 UTC
Created attachment 211695 [details]
Debug file with show the master version of qt-at-spi produced test result

Hy Joanie,

Monday Frederik wrote following letter in KDE A11y list:
"Thanks for poking and being the one to ask the right questions.
Mike Gorse just gave me the right hint and I'll set the state of tree and list items to "transient" now.
This fixes the cache becoming outdated since atspi2 doesn't cache the properties of these items.

If you want to try, rebuild you qt-at-spi from the master branch. I just pushed a fix.
If this is confirmed to work, I'll make another release since we have a few nice fixes accumulated now.

Greetings
Frederik"
My test results is following, I don't no need doing a fix for Orca side, or Frederik need working little the fix:
1. If I select a contact name, Orca spokening and presenting braille me different contact name with realy visual selected, unfortunately my wife confirmed this.
For example if Orca announce me I land with gerdave contact name the selected contact, realy herczeg.lajos contact name the selected contact. Absolute interesting, but where am I command showing good result.
2. If I land the first contact name and press Up arrow, Skype is crashed my machine if I using master branch of qt-at-spi.
Debug file showing some examples with moving contact list and where am I using result, so not need always choosing rename menu item dialog to verify the real selected contact name.
Debug file containing some tracebacks now.

Following commit containing Frederik doed fix:
"commit e2ab0017beb3ba6d2af8daf87be0a2c2069d9a27
Author: Frederik Gladhorn <frederik.gladhorn@nokia.com>
Date:   Mon Apr 9 14:05:04 2012 +0200

    Add state transient for list/tree items to fix caching issues
    
    This fixes children of these items changing and
    expanding of trees.
    Before libatspi2 would return outdated, cached items."

Attila
Attila


>
> Attila
> _______________________________________________
> kde-accessibility mailing list
> kde-accessibility@kde.org
> https://mail.kde.org/mailman/listinfo/kde-accessibility
Comment 10 Joanmarie Diggs (IRC: joanie) 2012-04-10 12:19:05 UTC
So I handled the timeout/process-appears-to-be hung tracebacks. But these things tend to bubble up elsewhere so please let me know if that occurs.

As for the crash, can you reliably reproduce it?
Comment 11 Hammer Attila 2012-04-10 12:39:36 UTC
Created attachment 211726 [details]
Fresh debug file with the latest commits result

Hy Joanie,

I always reproducable the Skype crash with qt-at-spi master branch, hopefuly I sent Frederik the right debug informations.
The new generated debug.out file showing following traceback error messages:
1. error message:
Traceback (most recent call last):
  • File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 253 in generate
    globalsDict[arg] = self._methodsDict[arg](obj, **args)
  • File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 647 in _generateColumnHeader
    role = args.get('role', obj.getRole())
  • File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43 in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

2. error message:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 222, in _dequeue
    self._processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 567, in _processObjectEvent
    script.processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/script.py", line 404, in processObjectEvent
    self.listeners[key](event)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 3429, in onStateChanged
    self.onFocus(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 3222, in onFocus
    orca.setLocusOfFocus(event, newFocus)
  File "/usr/local/lib/python2.7/dist-packages/orca/orca.py", line 528, in setLocusOfFocus
    event, oldLocusOfFocus, orca_state.locusOfFocus)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 1336, in locusOfFocusChanged
    if newLocusOfFocus.getRole() == pyatspi.ROLE_LINK:
  File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43, in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

Attila
Comment 12 Joanmarie Diggs (IRC: joanie) 2012-04-10 12:58:27 UTC
Handled the new ones, please try again.
Comment 13 Hammer Attila 2012-04-10 13:09:12 UTC
Created attachment 211729 [details]
Fresh result

Hy Joanie,

Repeated the test.
Now following tracebacks happened:
1. error message:
Traceback (most recent call last):
  • File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 253 in generate
    globalsDict[arg] = self._methodsDict[arg](obj, **args)
  • File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 995 in _generateRadioButtonGroup
    if obj.getRole() == pyatspi.ROLE_RADIO_BUTTON:
  • File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43 in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

2. error message:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 222, in _dequeue
    self._processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 567, in _processObjectEvent
    script.processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/script.py", line 404, in processObjectEvent
    self.listeners[key](event)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 3433, in onStateChanged
    self.onFocus(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 3226, in onFocus
    orca.setLocusOfFocus(event, newFocus)
  File "/usr/local/lib/python2.7/dist-packages/orca/orca.py", line 528, in setLocusOfFocus
    event, oldLocusOfFocus, orca_state.locusOfFocus)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/default.py", line 1347, in locusOfFocusChanged
    priorObj=oldLocusOfFocus)
  File "/usr/local/lib/python2.7/dist-packages/orca/speech_generator.py", line 121, in generateSpeech
    return self.generate(obj, **args)
  File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 186, in generate
    globalsDict['role'] = args.get('role', obj.getRole())
  File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43, in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

Before your last commit I generated a debug.out file with Thunderbird when I leave TB in a big message index containing folder.
Have similar error messages in the prewious debug.out file, but need testing again.
Opening a new report with Thunderbird related, or attach this report the thunderbird related debug file too?

Attila
Comment 14 Hammer Attila 2012-04-10 13:22:40 UTC
Thunderbird related error messages:
1. Error message:
Traceback (most recent call last):
  • File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 222 in _dequeue
    self._processObjectEvent(event)
  • File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 567 in _processObjectEvent
    script.processObjectEvent(event)
  • File "/usr/local/lib/python2.7/dist-packages/orca/script.py", line 404 in processObjectEvent
    self.listeners[key](event)
  • File "/usr/local/lib/python2.7/dist-packages/orca/scripts/toolkits/Gecko/script.py", line 1460 in onChildrenChanged
    and event.any_data.getRole() == pyatspi.ROLE_ALERT \
  • File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43 in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

2. error message:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 253, in generate
    globalsDict[arg] = self._methodsDict[arg](obj, **args)
  File "/usr/local/lib/python2.7/dist-packages/orca/braille_generator.py", line 193, in _generateAlertAndDialogCount
    self._script.utilities.unfocusedAlertAndDialogCount(obj)
  File "/usr/local/lib/python2.7/dist-packages/orca/script_utilities.py", line 1559, in unfocusedAlertAndDialogCount
    for child in app:
  File "/usr/lib/python2.7/dist-packages/pyatspi/Accessibility.py", line 30, in Accessible_getitem
    len=self.get_child_count()
  File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43, in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

3. error message:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/orca/generator.py", line 253, in generate
    globalsDict[arg] = self._methodsDict[arg](obj, **args)
  File "/usr/local/lib/python2.7/dist-packages/orca/speech_generator.py", line 1609, in _generateNewAncestors
    result = self._generateAncestors(obj, **args)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/toolkits/Gecko/speech_generator.py", line 427, in _generateAncestors
    roleInfo = self.getLocalizedRoleName(parent)
  File "/usr/local/lib/python2.7/dist-packages/orca/speech_generator.py", line 292, in getLocalizedRoleName
    nonlocalized = Atspi.role_get_name(role)
  File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43, in function
    return info.invoke(*args, **kwargs)
TypeError: Argument 0 does not allow None as a value

My oldest Thunderbird debug.out file have following possible interesting error messages, this situation Orca navigating very slow in Thunderbird folder, but hopefuly this errors already handled:
1. oldest error:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 222, in _dequeue
    self._processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/event_manager.py", line 567, in _processObjectEvent
    script.processObjectEvent(event)
  File "/usr/local/lib/python2.7/dist-packages/orca/script.py", line 404, in processObjectEvent
    self.listeners[key](event)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/toolkits/Gecko/script.py", line 1455, in onChildrenChanged
    if self.handleAsLiveRegion(event):
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/toolkits/Gecko/script.py", line 2906, in handleAsLiveRegion
    attrs = self._getAttrDictionary(event.any_data)
  File "/usr/local/lib/python2.7/dist-packages/orca/scripts/toolkits/Gecko/script.py", line 2877, in _getAttrDictionary
    return dict([attr.split(':', 1) for attr in obj.getAttributes()])
  File "/usr/lib/python2.7/dist-packages/gi/types.py", line 43, in function
    return info.invoke(*args, **kwargs)
GError: The process appears to be hung.

Attila
Comment 15 Joanmarie Diggs (IRC: joanie) 2012-04-10 13:27:48 UTC
Attila please stop pasting tracebacks in the comments. Really. It makes the bugs too long. It also makes it hard for me to see and separate your tracebacks from your text. It does not help.
Comment 16 Joanmarie Diggs (IRC: joanie) 2012-04-10 13:29:36 UTC
Comment on attachment 211357 [details]
Debug file with possible showing why happening this issue

Because reading the comments with tracebacks is too much of a pain, I am only reading debug.outs and obsoleting them when addressed.
Comment 17 Joanmarie Diggs (IRC: joanie) 2012-04-10 13:30:47 UTC
Comment on attachment 211695 [details]
Debug file with show the master version of qt-at-spi produced test result

Handled.
Comment 18 Joanmarie Diggs (IRC: joanie) 2012-04-10 13:33:55 UTC
Comment on attachment 211726 [details]
Fresh debug file with the latest commits result

handled
Comment 19 Joanmarie Diggs (IRC: joanie) 2012-04-10 13:58:54 UTC
Comment on attachment 211729 [details]
Fresh result

handled
Comment 20 Hammer Attila 2012-04-10 14:34:44 UTC
Created attachment 211740 [details]
Two debug file with Thunderbird related

Thunderbird is a good testing application now.
Two debug file generation showing me different errors, sending with attachment.

Attila
Comment 21 Joanmarie Diggs (IRC: joanie) 2012-04-10 17:27:24 UTC
Comment on attachment 211740 [details]
Two debug file with Thunderbird related

Handled.
Comment 22 Joanmarie Diggs (IRC: joanie) 2012-04-10 17:29:57 UTC
I just realized that I forgot to move this back to Orca having repurposed it to be the Great Timeout Handling bug, which would explain the spamorama Piñeiro mentioned.
Comment 23 Hammer Attila 2012-04-11 04:57:37 UTC
Created attachment 211804 [details]
Fresh debug.out file with yesterday latest commits

Joanie, I sending a new debug.out file with Thunderbird related.
I not tryed yet with you wrote gnome-3-4 branch of at-spi2 change, now I updating my system.
Have chance to resolve Mike change this type tracebacks with other apps, and faster launching for example Thunderbird with large folders?

Attila
Comment 24 Hammer Attila 2012-04-11 05:34:32 UTC
Created attachment 211807 [details]
Thunderbird related debug file after at-spi2-core update

Tracebacks is not changed, some traceback error messages equals the prewious debug.out file.
But have a new error with at-spi2 rolenames related, this is the last error message.
Happening this error when Orca want spokening me I land the "bugok helyimappák" object. The interesting thing the braille display right notify me Orca I land my bugs folder.
Need handling this error?
I ask this, because my system now little corrupted the language preferences, for example now In Orca I see the UI messages with hungarian, but the rolenames I hear with english, so I not sure full this is a real error.

Attila
Comment 25 Hammer Attila 2012-04-11 06:07:37 UTC
The localization related rolenames traceback error message is unfortunately valid.
I fixed my language preferences and doed a test with full right hungarian locale.

Attila
Comment 26 Hammer Attila 2012-04-11 06:17:11 UTC
Created attachment 211808 [details]
A process appears to be hung error containing debug.out when Orca want mapping script for Thunderbird

This debug.out file containing a process appears tobe hung error when Orca want mapping script for Thunderbird application with yet no longer exist.

Attila
Comment 27 Hammer Attila 2012-04-11 14:51:07 UTC
Created attachment 211839 [details]
A process apper be chunk traceback when I tested Pidgin

Unfortunately this traceback repeated me an another situation.
I tested Pidgin related the new at-spi2-core doed change in gnome-3-4 branch, sure by sure I maked a debug.out.
I think this error is happened with different place in the code, with prewious not attached.

Attila
Comment 28 Joanmarie Diggs (IRC: joanie) 2012-04-11 18:30:01 UTC
Comment on attachment 211804 [details]
Fresh debug.out file with yesterday latest commits

handled
Comment 29 Joanmarie Diggs (IRC: joanie) 2012-04-11 18:30:23 UTC
Comment on attachment 211807 [details]
Thunderbird related debug file after at-spi2-core update

handled
Comment 30 Joanmarie Diggs (IRC: joanie) 2012-04-11 18:30:41 UTC
Comment on attachment 211808 [details]
A process appears to be hung error containing debug.out when Orca want mapping script for Thunderbird

handled
Comment 31 Joanmarie Diggs (IRC: joanie) 2012-04-11 18:30:56 UTC
Comment on attachment 211839 [details]
A process apper be chunk traceback when I tested Pidgin

handled
Comment 32 Hammer Attila 2012-04-12 06:54:22 UTC
Created attachment 211904 [details]
Fresh debug file after I applied Mike patches and updated Orca with latest commits

This debug.out file I generated with Thunderbird a large folder (5800 messages).
The good news is following:
Tracebacks drastical decreased, only have two error messages in the debug.out file.

Attila
Comment 33 Joanmarie Diggs (IRC: joanie) 2012-04-12 18:07:22 UTC
Comment on attachment 211904 [details]
Fresh debug file after I applied Mike patches and updated Orca with latest commits

handled
Comment 34 Hammer Attila 2012-04-13 05:03:57 UTC
Created attachment 211969 [details]
Fresh debug file with Thunderbird related

This debug.out file containing only one message when I leave my Thunderbird in my orca-list folder (5800 messages have in this folder).

Attila
Comment 35 Joanmarie Diggs (IRC: joanie) 2012-04-13 12:50:01 UTC
Comment on attachment 211969 [details]
Fresh debug file with Thunderbird related

handled
Comment 36 Hammer Attila 2012-04-13 13:46:11 UTC
Created attachment 211995 [details]
I think this debug.out file producing right result

Hy Joanie,

I have got an absolute good news:
I sending sure by sure hopefuly the last debug.out file this bug related.
This debug.out file doesn't containing any traceback error messages with related this bug. You confirm all thinks working right if you looking this debug.out file?
If yes, I think feel free close this bug with resolved fixes. If other situation I found this type errors future, I will be report new bug, or attach this bug the debug file.

I tryed launching Thunderbird with large messages folders, three generated debug.out file showing this result.
Speech output is right spokening when Orca processing the large message list, braille output right present the braille display.
I don't no why need waiting about 45 second before Orca begin presenting braille output and begin talking the important informations, but the good news this is happening. What other a11y parts need fixing bugs this problem related? Thunderbird producing lot of a11y related events with don't need?

Attila
Comment 37 Joanmarie Diggs (IRC: joanie) 2012-04-13 15:01:22 UTC
Yay for good news!

Based on the unicode error experience I know for a fact that the minute we close this bug out, you will find another unhandled timeout. So, let's just leave this open for now and possibly scare the timeouts away. <grins>

As for your debug.out and the 45 seconds, looking through all the lines which report a time, the biggest seems to be 3.6 seconds (occurs once). You have 6 cases where something took around a second and a half. And everything else (over 600 instances) seems to be happening pretty quickly. So I'm not seeing anything jump out at me as Orca taking a crazy amount of time. But I believe what you are saying about the delay. So....

For the 3.5/3.6 release I am going to be continuing to clean up Orca's code, look for places where performance is bad, etc. You and I definitely need to spend some time figuring out why you are having these problems and what we can do to stop them. But that's for a different bugzilla bug and/or a list discussion. <smiles> My immediate goal is the most stable 3.4.1 we can get out the door.