Bug #9633

waitAny is failing to find images that are on the screen

Added by kytv 2015-06-21 13:53:49 . Updated 2015-09-22 15:19:44 .

Status:
Resolved
Priority:
High
Assignee:
Category:
Test suite
Target version:
Start date:
2015-06-21
Due date:
% Done:

100%

Feature Branch:
test/9633-fix-waitAny
Type of work:
Code
Blueprint:

Starter:
Affected tool:
Deliverable for:

Description

The functionality of waitAny would be incredibly useful for Feature #9517.

While retrying the connection to OFTC, I want to look for one of two images

  • PidginTailsChannelEntry.png
  • PidginReconnect.png

Even though one of the images is on the screen, I see

    Then Pidgin successfully connects to the "irc.oftc.net" account                # features/step_definitions/pidgin.rb:283
      FindFailed: can not find any of the images ["PidginTailsChannelEntry.png", "PidginReconnect.png"] on the screen
      Line ?, in File ? (RuntimeError)

However, if I use --retry-find the images will be found without my having to do anything more than pressing enter.

   When I activate the "irc.oftc.net" Pidgin account                              # features/step_definitions/pidgin.rb:273
[log] CLICK on (711,509)
    And I close Pidgin's account manager window                                    # features/step_definitions/pidgin.rb:268
calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]

FindFailed for: PidginTailsChannelEntry.png

Update the image and press RETURN to retry

FindFailed for: PidginReconnect.png

Update the image and press RETURN to retry

Forcing new Tor circuit... (attempt #1)
calling as root: pidof -x -o '%PPID' vidalia
call returned: [0, "6216\n", ""]
[log] TYPE "
[log] RIGHT CLICK on (728,11)
[log] CLICK on (782,105)
[log] CLICK on (363,509)
calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]

FindFailed for: PidginTailsChannelEntry.png

Update the image and press RETURN to retry

Forcing new Tor circuit... (attempt #2)
calling as root: pidof -x -o '%PPID' vidalia
call returned: [0, "6216\n", ""]
[log] TYPE "
[log] RIGHT CLICK on (728,11)
[log] CLICK on (782,105)
[log] CLICK on (363,509)
calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]

FindFailed for: PidginTailsChannelEntry.png

Update the image and press RETURN to retry

Forcing new Tor circuit... (attempt #3)
calling as root: pidof -x -o '%PPID' vidalia
call returned: [0, "6216\n", ""]
[log] TYPE "
[log] RIGHT CLICK on (728,11)
[log] CLICK on (782,105)
[log] CLICK on (363,509)
calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]

FindFailed for: PidginTailsChannelEntry.png

Update the image and press RETURN to retry

Forcing new Tor circuit... (attempt #4)
calling as root: pidof -x -o '%PPID' vidalia
call returned: [0, "6216\n", ""]
[log] TYPE "
[log] RIGHT CLICK on (728,11)
[log] CLICK on (782,105)
[log] CLICK on (363,509)
calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]

FindFailed for: PidginTailsChannelEntry.png

Update the image and press RETURN to retry

Forcing new Tor circuit... (attempt #5)
calling as root: pidof -x -o '%PPID' vidalia
call returned: [0, "6216\n", ""]
[log] TYPE "
[log] RIGHT CLICK on (728,11)
[log] CLICK on (782,105)
[log] CLICK on (363,509)

It’s entirely possible that my expectations for waitAny are incorrect. The code I’m using at the moment is the following:

Then /^Pidgin successfully connects to the "([^"]+)" account$/ do |account|
  next if @skip_steps_while_restoring_background
  expected_channel_entry = chan_image(account, default_chan(account), 'roaster')
  reconnect_button = 'PidginReconnect.png'
  tries = 0 
  until tries == $config["MAX_NEW_TOR_CIRCUIT_RETRIES"] do
    # Sometimes the OFTC welcome notice window pops up over the buddy list one...
    @vm.focus_window('Buddy List')
    what_we_see, region =
      @screen.waitAny([expected_channel_entry, reconnect_button], 60) 
    if what_we_see == expected_channel_entry
      break
    else
      tries += 1
      @screen.wait(reconnect_button, 30) 
      STDERR.puts "Forcing new Tor circuit... (attempt ##{tries})" if $config["DEBUG"]
      step "in Vidalia I force Tor to use a new circuit"
      @screen.wait_and_click(reconnect_button, 20) 
    end 
  end 
 @screen.wait(expected_channel_entry)
end

Subtasks


Related issues

Blocks Tails - Feature #6306: Write tests for I2P Resolved 2013-09-26 2015-07-15

History

#1 Updated by kytv 2015-06-22 04:32:10

Note: I now see that

what_we_see, region = @screen.waitAny([expected_channel_entry, reconnect_button], 60) 

would be better as

what_we_see, _ = @screen.waitAny([expected_channel_entry, reconnect_button], 60) 

to prevent assigning a value to a variable that we don’t care about.

#2 Updated by anonym 2015-06-27 08:30:21

  • Assignee set to anonym
  • Target version set to Tails_1.6

Haven’t verified yet.

#3 Updated by anonym 2015-06-27 09:03:50

The following is what I am testing (based on the code in the description) against kytv:test/9517-retry-oftc. Note that I added debug output of what waitAny() returns.

--- a/features/step_definitions/pidgin.rb
+++ b/features/step_definitions/pidgin.rb
@@ -298,6 +298,7 @@ end
 Then /^Pidgin successfully connects to the "([^"]+)" account$/ do |account|
   next if @skip_steps_while_restoring_background
   expected_channel_entry = chan_image(account, default_chan(account), 'roster')
+  reconnect_button = 'PidginReconnect.png'
   tries = 0
   until tries == $config["MAX_NEW_TOR_CIRCUIT_RETRIES"] do
     # Sometimes the OFTC welcome notice window pops up over the buddy list one...
@@ -309,16 +310,17 @@ Then /^Pidgin successfully connects to the "([^"]+)" account
$/ do |account|
       # conversation window. At worst, the test will still fail...
       close_pidgin_conversation_window(account)
     end
-
-    # FIXME This should be modified to use waitAny once <del><a class='issue tracker-1 status-3 priority-6 priority-default closed child' href='/code/issues/9633' title='waitAny is failing to find images that are on the screen'>Bug #9633</a></del> is addressed
-    begin
-      @screen.wait(expected_channel_entry, 60)
+    what_we_see, _ =
+      @screen.waitAny([expected_channel_entry, reconnect_button], 60)
+    STDERR.puts "XXX GOT: #{what_we_see}"
+    if what_we_see == expected_channel_entry
       break
-    rescue FindFailed
+    else
       tries += 1
+      @screen.wait(reconnect_button, 30)
       STDERR.puts "Forcing new Tor circuit... (attempt ##{tries})" if $config["DEBUG"]
       step "in Vidalia I force Tor to use a new circuit"
-      @screen.wait_and_click('PidginReconnect.png', 20)
+      @screen.wait_and_click(reconnect_button, 20)
     end
   end
   @screen.wait(expected_channel_entry, 10)

#4 Updated by anonym 2015-06-27 09:19:13

  • Status changed from New to Confirmed

It worked a few times, but I’ve got this now:

calling as amnesia: xdotool search --name 'Buddy List' windowactivate --sync
call returned: [0, "", ""]
XXX GOT: 
    Then Pidgin successfully connects to the "irc.oftc.net" account
      FindFailed: can not find PidginReconnect.png on the screen.
      Line ?, in File ? (RuntimeError)
      features/pidgin.feature:22:in `Then Pidgin successfully connects to the "irc.oftc.net" account' 


which means that findAny() returned an empty string, which should be impossible (unless the empty string is one of the images it’s looking for, which shouldn’t work either). Or that it returned nil. Note that I didn’t get the same FindFailed error later either. Hmm.

#5 Updated by kytv 2015-06-27 11:35:38

anonym wrote:
> It worked a few times, but I’ve got this now:
> […]
> which means that findAny() returned an empty string, which should be impossible (unless the empty string is one of the images it’s looking for, which shouldn’t work either). Or that it returned nil. Note that I didn’t get the same FindFailed error later either. Hmm.

This, unfortunately (or fortunately, depending on your point of view) is what I saw. It worked most of the time but the success rate was less than 100%.

#6 Updated by anonym 2015-06-27 11:40:37

  • Assignee changed from anonym to kytv

Ok. I believe we’ve stumbled upon some strange Rjb bug. It seems that Rjb::throw isn’t completely reliable. In waitAny we have return self.findAny(images), and it turns out that in the failing cases the findAny call return nil. It does that because the Rjb::trow in findAny doesn’t kill execution and throw the exception, so its return value, which happens to be nil, is returned instead. Urgh. Worse: sometimes the exception is thrown, but later (from another thread?). This is messy…

This fixes the problem for me. Can you please try, kytv?

--- a/features/support/helpers/sikuli_helper.rb
+++ b/features/support/helpers/sikuli_helper.rb
@@ -36,6 +36,9 @@ for p in package_members
   mod.const_set(class_name, imported_class)
 end

+class FindAnyFailed < RuntimeError
+end
+
 def findfailed_hook(pic)
   STDERR.puts ""
   STDERR.puts "FindFailed for: #{pic}"
@@ -142,8 +145,7 @@ def sikuli_script_proxy.new(*args)
       end
     end
     # If we've reached this point, none of the images could be found.
-    Rjb::throw('org.sikuli.script.FindFailed',
-               "can not find any of the images #{images} on the screen")
+    raise FindAnyFailed.new("can not find any of the images #{images} on the screen")
   end

   def s.waitAny(images, time)
@@ -151,14 +153,13 @@ def sikuli_script_proxy.new(*args)
       loop do
         begin
           return self.findAny(images)
-        rescue FindFailed
+        rescue FindAnyFailed
           # Ignore. We want to retry until we timeout.
         end
       end
     end
   rescue Timeout::Error
-    Rjb::throw('org.sikuli.script.FindFailed',
-               "can not find any of the images #{images} on the screen")
+    raise FindAnyFailed.new("can not find any of the images #{images} on the screen")
   end

   def s.hover_point(x, y)

#7 Updated by kytv 2015-06-27 18:48:20

Looking good so far. :) I patched my kytv:test/9517-retry-oftc with Bug #9633#note-3 and it’s working as expected.

We’re inching closer to crossing out Feature #8539 :)

I’m still stress-testing the modified kytv:test/9517-retry-oftc with the above patch, but I’m pretty sure this bug is fixed.

#8 Updated by kytv 2015-06-29 02:11:26

  • blocks Feature #9653: Optimize retrying to connect to IRC servers in testsuite using waitAny/existsAny added

#9 Updated by kytv 2015-06-29 02:12:04

  • Assignee changed from kytv to anonym

I’m satisfied with your proposed changes.

#10 Updated by kytv 2015-09-04 13:07:28

  • QA Check set to Dev Needed

#11 Updated by anonym 2015-09-07 17:01:11

kytv wrote:
> I’m satisfied with your proposed changes.

I’m not sure I am, though. Sure it seems to work, but now there’s another exception than FindFailed, which is unexpected for any of the Sikuli Screen methods. It would be ok-ish if FindAnyFailed could be made a subclass of FindFailed.

I am also scared about what implications this may have in other places where we rely on catching FindFailed exceptions.

I wonder if there’s some subtlety with the nestedness of the exception-catching of waitAny() calling findAny() similar to the situation with try_for(). If so I do not get why my “fix” solves the problem, since it should create the same situation. Argh. ETOOTIRED.

#12 Updated by anonym 2015-09-07 18:18:43

  • Status changed from Confirmed to In Progress

Applied in changeset commit:f09d05a75853414ca19f0003050f61f2c613fb1d.

#13 Updated by anonym 2015-09-07 18:20:05

  • Assignee changed from anonym to kytv
  • % Done changed from 0 to 50
  • QA Check changed from Dev Needed to Ready for QA
  • Feature Branch set to test/9633-fix-waitAny

Woo, I think I’ve found a proper solution. I only have a theory of why it works (see the commit message) but at this stage that’s good enough for me.

#14 Updated by kytv 2015-09-12 15:46:11

  • blocked by deleted (Feature #9653: Optimize retrying to connect to IRC servers in testsuite using waitAny/existsAny)

#15 Updated by kytv 2015-09-12 17:49:11

#16 Updated by kytv 2015-09-12 17:53:05

  • Assignee changed from kytv to intrigeri

I’m happy with this fix. Tested and working fine in the branch that I wanted this fix for. :)

#17 Updated by kytv 2015-09-13 16:08:45

  • blocks Feature #9653: Optimize retrying to connect to IRC servers in testsuite using waitAny/existsAny added

#18 Updated by kytv 2015-09-14 09:48:24

  • Assignee changed from intrigeri to anonym
  • QA Check changed from Ready for QA to Dev Needed

Reassigning to anonym based on a discussion on IRC.

With the following code

    on_screen, _ = @screen.waitAny([expected_channel_entry, reconnect_button], 10)
    if on_screen != expected_channel_entry
      raise StandardError.new("Connecting to account #{account} failed.")
    end
    @screen.wait(expected_channel_entry)

wrapped in a function like retry_tor from Bug #10116 (revision 35ee5cf32d009e69b78c31632ad5934668977384) yields the following result when none of the images are found:

When I activate the “I2P” Pidgin account # features/step_definitions/pidgin.rb:293
[log] CLICK on (711,509)
And I close Pidgin’s account manager window # features/step_definitions/pidgin.rb:289
calling as amnesia: xdotool search —name ‘Buddy List’ windowactivate —sync
call returned: [0, “”, “”]
Operation failed (Try 1 of 10) with:
StandardError: Connecting to account I2P failed.
Then Pidgin successfully connects to the “I2P” account # features/step_definitions/pidgin.rb:318
FindFailed: can not find any of the images [“PidginI2PChannelEntry.png”, “PidginReconnect.png”] on the screen
Line ?, in File ? (RuntimeError)
features/i2p.feature:62:in `Then Pidgin successfully connects to the “I2P” account’
And I can join the “#i2p” channel on “I2P” # features/step_definitions/pidgin.rb:365
Scenario failed at time 00:06:59

#19 Updated by intrigeri 2015-09-15 12:02:42

  • Priority changed from Normal to High

(Blocks a high-prio ticket.)

#20 Updated by anonym 2015-09-16 14:44:21

  • Assignee changed from anonym to kytv
  • QA Check changed from Dev Needed to Ready for QA

I can reproduce it. Indeed, Rjb::throw apparently doesn’t work very well. It seems like Ruby won’t block execution until it has received the Java exception, and in fact it may even get lost completely. I’ve even seen it appear suddenly later, after the scenario has already failed due to another exception being raised. Madness. At least we seem to not have this problem when some Java method we call (via Rjb) throws the exception (e.g. like all those Sikuli methods).

Indeed, it seems we need to introduce a new excetion for the *any() methods. Pushed.

#21 Updated by kytv 2015-09-17 08:59:18

  • Assignee changed from kytv to intrigeri

anonym wrote:

> Indeed, it seems we need to introduce a new excetion for the *any() methods. Pushed.

That seemed to solve the problem. Back to intrigeri for his skillful nitpicking.

#22 Updated by intrigeri 2015-09-17 12:28:01

  • % Done changed from 50 to 60

I don’t fully understand the code but it doesn’t sound crazy and I’m the third one looking at it. Running what seem to be the two affected features: features/pidgin.feature features/unsafe_browser.feature.

#23 Updated by intrigeri 2015-09-17 13:25:25

  • Status changed from In Progress to Fix committed
  • % Done changed from 60 to 100
  • QA Check changed from Ready for QA to Pass

Merged (commit:b8d2a80)!

#24 Updated by intrigeri 2015-09-17 13:25:59

  • Assignee deleted (intrigeri)

#25 Updated by bertagaz 2015-09-22 15:19:33

  • blocked by deleted (Feature #9653: Optimize retrying to connect to IRC servers in testsuite using waitAny/existsAny)

#26 Updated by bertagaz 2015-09-22 15:19:44

  • Status changed from Fix committed to Resolved
  • QA Check deleted (Pass)