Bug #11409

Deal with the 'Dogtail: warning: application may be hanging' bug

Added by anonym 2016-05-11 03:11:10 . Updated 2019-08-30 10:24:09 .

Status:
Resolved
Priority:
Normal
Assignee:
anonym
Category:
Test suite
Target version:
Start date:
2016-05-11
Due date:
% Done:

0%

Feature Branch:
Type of work:
Research
Blueprint:

Starter:
Affected tool:
Deliverable for:

Description

When that warning is displayed in the debug logs of dogtail it often means that dogtail will fail. See this log (taken from Feature #10721#note-11):

[...]
calling as amnesia: mktemp
call returned: [0, "/tmp/tmp.kg0NHEhCeZ\n", ""]
calling as root: rm -f '/tmp/tmp.kg0NHEhCeZ'
call returned: [0, "", ""]
calling as amnesia: echo '#!/usr/bin/python
from dogtail import tree
from dogtail.config import config
config.searchShowingOnly = True
application = tree.root.application('"'"'gedit'"'"')
application.button('"'"'New'"'"').click()' >> '/tmp/tmp.kg0NHEhCeZ'
call returned: [0, "", ""]
calling as amnesia: /usr/bin/python '/tmp/tmp.kg0NHEhCeZ'
call returned: [0, "Creating logfile at /tmp/dogtail-amnesia/logs/tmp.kg0NHEhCeZ_20160425-195535_debug ...\nDogtail: warning: application may be hanging\nClicking on [push button | New]\nMouse button 1 click at (207,70)\n", ""]
calling as root: rm -f '/tmp/tmp.kg0NHEhCeZ'
call returned: [0, "", ""]
calling as amnesia: mktemp
call returned: [0, "/tmp/tmp.qHGZBlkVKv\n", ""]
calling as root: rm -f '/tmp/tmp.qHGZBlkVKv'
call returned: [0, "", ""]
calling as amnesia: echo '#!/usr/bin/python
from dogtail import tree
from dogtail.config import config
config.searchShowingOnly = True
application = tree.root.application('"'"'gedit'"'"')
application.child(roleName='"'"'text'"'"').click(button=3)' >> '/tmp/tmp.qHGZBlkVKv'
call returned: [0, "", ""]
calling as amnesia: /usr/bin/python '/tmp/tmp.qHGZBlkVKv'
call returned: [0, "Creating logfile at /tmp/dogtail-amnesia/logs/tmp.qHGZBlkVKv_20160425-195556_debug ...\nDogtail: warning: application may be hanging\nClicking on [text | ]\nMouse button 3 click at (511,399)\n", ""]
calling as root: rm -f '/tmp/tmp.qHGZBlkVKv'
call returned: [0, "", ""]
calling as amnesia: mktemp
call returned: [0, "/tmp/tmp.dBE66obICt\n", ""]
calling as root: rm -f '/tmp/tmp.dBE66obICt'
call returned: [0, "", ""]
calling as amnesia: echo '#!/usr/bin/python
from dogtail import tree
from dogtail.config import config
config.searchShowingOnly = True
application = tree.root.application('"'"'gedit'"'"')
application.menuItem('"'"'Paste'"'"').click()' >> '/tmp/tmp.dBE66obICt'
call returned: [0, "", ""]
calling as amnesia: /usr/bin/python '/tmp/tmp.dBE66obICt'
call returned: [1, "Creating logfile at /tmp/dogtail-amnesia/logs/tmp.dBE66obICt_20160425-195618_debug ...\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 3)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 4)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 5)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 6)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 7)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 8)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 9)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 10)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 11)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 12)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 13)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 14)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 15)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 16)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 17)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 18)\nsearching for descendent of [application | gedit]: \"Paste\" menuitem (attempt 19)\nTraceback (most recent call last):\n  File \"/tmp/tmp.dBE66obICt\", line 6, in <module>\n    application.menuItem('Paste').click()\n  File \"/usr/lib/python2.7/dist-packages/dogtail/tree.py\", line 1008, in menuItem\n    return self.findChild(predicate.IsAMenuItemNamed(menuItemName=menuItemName), recursive, showingOnly=showingOnly)\n  File \"/usr/lib/python2.7/dist-packages/dogtail/tree.py\", line 897, in findChild\n    raise SearchError(describeSearch(self, pred, recursive, debugName))\nSearchError: descendent of [application | gedit]: \"Paste\" menuitem\n\n", ""]
calling as root: rm -f '/tmp/tmp.dBE66obICt'
call returned: [0, "", ""]
    And I symmetrically encrypt the message with password "asdf"      # features/step_definitions/encryption.rb:143
      Command failed: /usr/bin/python '/tmp/tmp.dBE66obICt'
      error code: 1
      stderr: .
      <false> is not true. (ExecutionFailedInVM)
      ./features/support/helpers/vm_helper.rb:441:in `rescue in execute_successfully'
      ./features/support/helpers/vm_helper.rb:438:in `execute_successfully'
      ./features/support/helpers/dogtail.rb:87:in `run'
      ./features/support/helpers/dogtail.rb:203:in `block (2 levels) in <class:Node>'
      ./features/step_definitions/encryption.rb:68:in `gedit_paste_into_a_new_tab'
      ./features/step_definitions/encryption.rb:149:in `/^I symmetrically encrypt the message with password "([^"]+)"$/'
      features/encryption.feature:34:in `And I symmetrically encrypt the message with password "asdf"'
    Then I can decrypt the encrypted message                          # features/step_definitions/encryption.rb:123
[...]


The click():s simply do not happen.


Files

debug.log (231942 B) anonym, 2016-05-11 03:16:30

Subtasks


Related issues

Blocked by Tails - Bug #11091: Deal with October 2016 false positive scenarios Resolved 2016-10-05 2016-11-05
Blocked by Tails - Bug #11092: Deal with November 2016 false positive scenarios Resolved 2016-11-05 2016-12-05

History

#1 Updated by anonym 2016-05-11 03:25:35

Attached is the full log for the excerpt in the ticket description. Note that it was run from commit:330bcab9a100471963556cbeaf2889f1e0908de8 and that the code has since been reverted (commit:339fced5d1da8c28434a4360eb7acd8860c0e9d3) because of this bug.

The commit in dogtail that adds this warning message is 4e5e19a17b7df43104561eb5183ca4d60bae57fe and it might be interesting to look into further for clues. It’s commit message says: “Added a workaround for situations when a previously crashed application still registered with at-spi blocks search.”. I wonder if e.g. gpgApplet does something crappy here?

#2 Updated by anonym 2016-08-31 05:02:34

  • Target version changed from Tails_2.6 to Tails_2.9.1

I’ll keep an eye on whether this error seem to pop up on Jenkins together with Dogtail failures. If not, I’ll just close it.

#3 Updated by intrigeri 2016-12-05 20:11:07

  • blocked by Bug #11091: Deal with October 2016 false positive scenarios added

#4 Updated by intrigeri 2016-12-05 20:11:10

  • blocks Bug #11092: Deal with November 2016 false positive scenarios added

#5 Updated by intrigeri 2016-12-05 20:11:43

  • Target version changed from Tails_2.9.1 to Tails 2.10

Let’s see once we have the data from Jenkins. Note that Tails 3.0 won’t have the Perl version of the OpenPGP applet GUI.

#6 Updated by intrigeri 2016-12-19 14:21:03

  • blocked by deleted (Bug #11092: Deal with November 2016 false positive scenarios)

#7 Updated by intrigeri 2016-12-19 14:21:11

  • blocked by Bug #11092: Deal with November 2016 false positive scenarios added

#8 Updated by intrigeri 2016-12-19 14:42:28

#9 Updated by intrigeri 2016-12-19 19:18:30

I’ve not noticed any such thing happening on stable or devel, on Jenkins, in October nor November.

#10 Updated by intrigeri 2016-12-19 19:19:13

  • Target version deleted (Tails 2.10)

(So dropping the target version. Let’s revisit if we see it again.)

#11 Updated by intrigeri 2019-08-30 10:24:09

  • Status changed from Confirmed to Resolved

I’ve grep’ed all debug.log files we currently have on Jenkins and could find no single instance of this problem, so I’m going to assume that the root cause was fixed since.