Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Intermittent timeouts performing gestures in Xcode 6.1 targeting iOS 8.1 simulators #585

Closed
JaniJegoroff opened this issue Oct 30, 2014 · 26 comments
Closed

Intermittent timeouts performing gestures in Xcode 6.1 targeting iOS 8.1 simulators #585

JaniJegoroff opened this issue Oct 30, 2014 · 26 comments

Comments

@JaniJegoroff
Copy link

Background
This is a new issue for a discussion originally started in #566

Most users are experiencing intermitted timeouts but I have a push notification scenario where I can reproduce issue every time.

Environment
Xcode 6.1
Calabash 0.11.3
run_loop 1.0.9
8.1 simulators

My original use case
I was working with push notification related scenario today and came across with timeout issue as well. Issue is reproducible every time. I'm writing values to NSUserDefaults during this scenario. Scenario is about showing custom "would you like to accept push notifications" screen to the user. After user taps two buttons (Sure and Next) in notifications screen then system level push notification alert view is shown. UI flow is like below:

<Navigation to custom notification screen and writing values to NSUserDefaults>
Given notification screen is displayed
When user taps "Sure" button
And user taps "Next" button
Then notification screen is dismissed
And system level push notification alert view is displayed
And Calabash dismisses system level alert view automatically

UI flow is completed correctly and Calabash automatically dismisses system level alert view. In spite of that tapping the "Next" button causes a timeout for some reason.

curl:

Janis-MacBook-Air:~ janijegoroff$ curl http://localhost:37265/version
{"app_version":"1.4","outcome":"SUCCESS","app_id":"myBundle","simulator_device":"iPad","version":"0.11.3","app_name":"myApp","iphone_app_emulated_on_ipad":false,"4inch":false,"git":{"remote_origin":"[email protected]:calabash\/calabash-ios-server.git","branch":"master","revision":"40c6245"},"screen_dimensions":{"scale":2,"width":1536,"sample":1,"height":2048},"iOS_version":"8.1","system":"x86_64","simulator":""}

Debug trace:

Janis-Air:myApp janijegoroff$ DEBUG=1 DEBUG_HTTP=1 cucumber -p dev_ipad --tags @accept_notifications
Using the dev_ipad, sim_ipad_retina_81, reset, features, tags_default_ipad, tags_ci, tags_ipad and tags_skip_pending profiles...
@notifications @ci @ipad @iphone
Feature: Notifications
  As a User
  I have an option to accept or decline notification when new content is published
  So that I can control notifications

  @accept_notifications
  Scenario: Accept notifications          # Calabash/features/notifications.feature:20

INFO: Using uia strategy: 'preferences'
Preparation took 2.245576 seconds
{
                        :app => "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app",
                       :args => [],
    :bundle_dir_or_bundle_id => "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app",
                  :bundle_id => "myBundle",
                     :device => "iphone",
              :device_target => "iPad Retina (8.1 Simulator)",
              :launch_method => :instruments,
             :launch_retries => 5,
                   :log_file => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/run_loop.out",
                  :no_launch => false,
                    :no_stop => false,
                      :reset => true,
                :results_dir => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz",
          :results_dir_trace => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/trace",
                     :script => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/_run_loop.js",
                :sdk_version => nil,
                       :udid => "iPad Retina (8.1 Simulator)",
               :uia_strategy => :preferences,
                      :xcode => "6.1",
                 :xcode_path => "/Applications/Xcode61/Xcode.app/Contents/Developer"
}

### Starting on iPad Retina (8.1 Simulator) App: /Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app ###
2014-10-28 22:29:02 +0000 xcrun instruments -w "iPad Retina (8.1 Simulator)" -D "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/trace" -t "Automation" "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app" -e UIARESULTSPATH /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz -e UIASCRIPT /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/_run_loop.js  &> /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/run_loop.out
Launching took 9.967125 seconds
= Request

! CONNECT TO localhost:37265
! CONNECTION ESTABLISHED
POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:12 GMT
Content-Length: 83
Host: localhost:37265

{"query":null,"operation":{"method_name":"orientation","arguments":["status_bar"]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 72
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:12 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"down","results":["down"],"outcome":"SUCCESS"}= Request

POST /play HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:12 GMT
Content-Length: 135
Host: localhost:37265

{"events":"YnBsaXN0MDChAdMCBAYDBQdURGF0YUQDAAAAoFRUaW1lEwAAAbhNBUVUVFR5cGUQ
MggKERYcISovAAAAAAAAAQEAAAAAAAAACAAAAAAAAAAAAAAAAAAAADE=
"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:12 GMT

22
{"results":[],"outcome":"SUCCESS"}
0

= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:12 GMT
Content-Length: 93
Host: localhost:37265

{"query":"view marked:'homeLaunchButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 484
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:12 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"Main menu","selected":false,"enabled":true,"id":null,"rect":{"center_x":512,"y":174,"width":540,"x":242,"center_y":196,"height":44},"label":"homeLaunchButton","description":"<QTableViewCell: 0x7bed85a0; baseClass = UITableViewCell; frame = (0 100; 540 44); text = 'Main menu'; autoresize = W; layer = <CALayer: 0x7bed8740>>","alpha":1,"class":"QTableViewCell","frame":{"y":100,"width":540,"x":0,"height":44}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:15 GMT
Content-Length: 93
Host: localhost:37265

{"query":"view marked:'homeLaunchButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 484
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:15 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"Main menu","selected":false,"enabled":true,"id":null,"rect":{"center_x":512,"y":174,"width":540,"x":242,"center_y":196,"height":44},"label":"homeLaunchButton","description":"<QTableViewCell: 0x7bed85a0; baseClass = UITableViewCell; frame = (0 100; 540 44); text = 'Main menu'; autoresize = W; layer = <CALayer: 0x7bed8740>>","alpha":1,"class":"QTableViewCell","frame":{"y":100,"width":540,"x":0,"height":44}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 196}')
= Request

POST /uia HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:15 GMT
Content-Length: 47
Host: localhost:37265

{"command":"uia.tapOffset('{:x 512, :y 196}')"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:15 GMT

4d
{"results":[{"status":"success","value":true,"index":0}],"outcome":"SUCCESS"}
0

Result
{"status"=>"success", "value"=>true, "index"=>0}
= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:16 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:16 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:16 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:16 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:16 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:16 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:17 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:17 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:17 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 607
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:17 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UICollectionView: 0x7c231400; frame = (0 0; 1024 768); clipsToBounds = YES; gestureRecognizers = <NSArray: 0x7d608660>; animations = { opacity=<CABasicAnimation: 0x7d60f680>; }; layer = <CALayer: 0x7d6050f0>; contentOffset: {0, -64}; contentSize: {1022, 1246}> collection view layout: <SUSPhotoReelFlowLayout: 0x7be00210>","id":null,"label":null,"alpha":1,"class":"UICollectionView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:18 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:18 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x7bf9d1b0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x7bf82c60>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:18 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:18 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x7bf9d1b0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x7bf82c60>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:21 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:21 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x7bf9d1b0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x7bf82c60>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 255, :y 643.25}')
= Request

POST /uia HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:21 GMT
Content-Length: 50
Host: localhost:37265

{"command":"uia.tapOffset('{:x 255, :y 643.25}')"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:21 GMT

4d
{"results":[{"status":"success","value":true,"index":1}],"outcome":"SUCCESS"}
0

Result
{"status"=>"success", "value"=>true, "index"=>1}
= Request

** WRITE VALUES TO NSUSERDEFAULTS **

POST /userprefs HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:21 GMT
Content-Length: 53
Host: localhost:37265

{"key":"NOTIFICATION_SCREEN_PRESENTED_KEY","value":1}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 35
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:21 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"results":[1],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:21 GMT
Content-Length: 93
Host: localhost:37265

{"query":"navigationItemButtonView first","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 528
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:21 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":false,"rect":{"center_x":38,"y":26,"width":52,"x":12,"center_y":41,"height":30},"description":"<UINavigationItemButtonView: 0x7d630710; frame = (12 6; 52 30); opaque = NO; userInteractionEnabled = NO; animations = { opacity=<CABasicAnimation: 0x7d632de0>; position=<CABasicAnimation: 0x7d632e90>; }; layer = <CALayer: 0x7d6305e0>>","id":null,"label":"Back","alpha":1,"class":"UINavigationItemButtonView","frame":{"y":6,"width":52,"x":12,"height":30}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 38, :y 41}')
= Request

POST /uia HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:21 GMT
Content-Length: 45
Host: localhost:37265

{"command":"uia.tapOffset('{:x 38, :y 41}')"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:21 GMT

4d
{"results":[{"status":"success","value":true,"index":2}],"outcome":"SUCCESS"}
0

Result
{"status"=>"success", "value"=>true, "index"=>2}
= Request

POST /userprefs HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:22 GMT
Content-Length: 53
Host: localhost:37265

{"key":"NOTIFICATION_SCREEN_PRESENTED_KEY","value":1}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 37
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:22 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"results":[1,1],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:22 GMT
Content-Length: 84
Host: localhost:37265

{"query":"view:'SUSLoadingView'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:22 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

** WAIT FOR NOTIFICATION SCREEN **

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:22 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:22 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:22 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 445
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:23 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UIView: 0x7bfcecb0; frame = (0 0; 1024 768); autoresize = W+H; animations = { position=<CASpringAnimation: 0x7d6469a0>; }; layer = <CALayer: 0x7bfa23a0>>","id":"notificationScreen","label":null,"alpha":1,"class":"UIView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:23 GMT
Content-Length: 84
Host: localhost:37265

{"query":"view:'SUSLoadingView'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:23 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:23 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 445
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:23 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UIView: 0x7bfcecb0; frame = (0 0; 1024 768); autoresize = W+H; animations = { position=<CASpringAnimation: 0x7d6469a0>; }; layer = <CALayer: 0x7bfa23a0>>","id":"notificationScreen","label":null,"alpha":1,"class":"UIView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}    Given Notification screen is opened   # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
= Request

** TAP SURE BUTTON **

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:23 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'sureButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:23 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"sureButton","description":"<UIButton: 0x7d645040; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7d626240>>","label":"Sure","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:26 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'sureButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:26 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"sureButton","description":"<UIButton: 0x7d645040; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7d626240>>","label":"Sure","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 578}')
= Request

POST /uia HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:26 GMT
Content-Length: 47
Host: localhost:37265

{"command":"uia.tapOffset('{:x 512, :y 578}')"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:26 GMT

4d
{"results":[{"status":"success","value":true,"index":3}],"outcome":"SUCCESS"}
0

Result
{"status"=>"success", "value"=>true, "index"=>3}
= Request

** TAP NEXT BUTTON **

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:26 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'nextButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:26 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"nextButton","description":"<UIButton: 0x7d6429e0; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7d6139e0>>","label":"Next","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:29 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'nextButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:29:29 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"nextButton","description":"<UIButton: 0x7d6429e0; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7d6139e0>>","label":"Next","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 578}')
= Request

POST /uia HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:29:29 GMT
Content-Length: 47
Host: localhost:37265

{"command":"uia.tapOffset('{:x 512, :y 578}')"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Tue, 28 Oct 2014 22:29:29 GMT

69
{"details":"","outcome":"FAILURE","reason":"Timed out running command uia.tapOffset('{:x 512, :y 578}')"}
0

    When I accept notifications           # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
      uia action failed because: Timed out running command uia.tapOffset('{:x 512, :y 578}')
       (RuntimeError)
      ./Calabash/features/support/common_utils.rb:54:in `tap_element'
      ./Calabash/features/support/page_objects/base_page.rb:50:in `method_missing'
      ./Calabash/features/support/meta_code_generator.rb:82:in `block (2 levels) in create_tap_element_methods'
      ./Calabash/features/support/page_objects/notification_screen.rb:39:in `next'
      ./Calabash/features/support/page_objects/notification_screen.rb:23:in `accept'
      ./Calabash/features/support/page_objects/notification_screen.rb:18:in `handle_notifications'
      Calabash/features/notifications.feature:22:in `When I accept notifications'
    Then Notification screen is dismissed # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
= Request

! CONNECTION CLOSED
! CONNECT TO localhost:37265
! CONNECTION ESTABLISHED
POST /exit HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Tue, 28 Oct 2014 22:31:34 GMT
Content-Length: 78
Host: localhost:37265

{"post_resign_active_delay":0.4,"post_will_terminate_delay":0.4,"exit_code":0}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 2
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Tue, 28 Oct 2014 22:31:34 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{}Sending 'QUIT' to instruments process '29989'
Waiting for instruments '29989' to terminate

Failing Scenarios:
cucumber -p dev_ipad -p sim_ipad_retina_81 -p reset -p features -p tags_default_ipad -p tags_ci -p tags_ipad -p tags_skip_pending Calabash/features/notifications.feature:20 # Scenario: Accept notifications

1 scenario (1 failed)
3 steps (1 failed, 1 skipped, 1 passed)
2m37.907s

run_loop.out:

Janis-Air:myApp-iOS janijegoroff$ cat /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/run_loop.out
Waiting for device to boot...
2014-10-28 22:29:12 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":0}
END_OUTPUT
2014-10-28 22:29:12 +0000 Default: *******************************************************
2014-10-28 22:29:15 +0000 Default: index 0 is command: uia.tapOffset('{:x 512, :y 196}')
2014-10-28 22:29:15 +0000 Debug: target.tapWithOptions({x:"512", y:"196"}, )
2014-10-28 22:29:16 +0000 Default: Success: true
2014-10-28 22:29:16 +0000 Default: Write result...
2014-10-28 22:29:16 +0000 Default: Check successful storage...
2014-10-28 22:29:16 +0000 Default: Storage succeeded: 0
2014-10-28 22:29:21 +0000 Default: index 1 is command: uia.tapOffset('{:x 255, :y 643.25}')
2014-10-28 22:29:21 +0000 Debug: target.tapWithOptions({x:"255", y:"643.25"}, )
2014-10-28 22:29:21 +0000 Default: Success: true
2014-10-28 22:29:21 +0000 Default: Write result...
2014-10-28 22:29:21 +0000 Default: Check successful storage...
2014-10-28 22:29:21 +0000 Default: Storage succeeded: 1
2014-10-28 22:29:21 +0000 Default: index 2 is command: uia.tapOffset('{:x 38, :y 41}')
2014-10-28 22:29:22 +0000 Debug: target.tapWithOptions({x:"38", y:"41"}, )
2014-10-28 22:29:22 +0000 Default: Success: true
2014-10-28 22:29:22 +0000 Default: Write result...
2014-10-28 22:29:22 +0000 Default: Check successful storage...
2014-10-28 22:29:22 +0000 Default: Storage succeeded: 2
2014-10-28 22:29:26 +0000 Default: index 3 is command: uia.tapOffset('{:x 512, :y 578}')
2014-10-28 22:29:26 +0000 Debug: target.tapWithOptions({x:"512", y:"578"}, )
2014-10-28 22:29:26 +0000 Default: Success: true
2014-10-28 22:29:26 +0000 Default: Write result...
2014-10-28 22:29:26 +0000 Default: Check successful storage...
2014-10-28 22:29:26 +0000 Default: Storage succeeded: 3
2014-10-28 22:29:30 +0000 Default: index 4 is command: uia.tapOffset('{:x 512, :y 578}')
2014-10-28 22:29:30 +0000 Debug: target.tapWithOptions({x:"512", y:"578"}, )
2014-10-28 22:29:30 +0000 Default: Success: true
2014-10-28 22:29:30 +0000 Default: Write result...
2014-10-28 22:29:30 +0000 Default: Check successful storage...
2014-10-28 22:29:30 +0000 Default: Storage succeeded: 4
2014-10-28 22:29:31 +0000 Default: OUTPUT_JSON:
{"output":{"output":"on alert"},"last_index":4}
END_OUTPUT
2014-10-28 22:29:31 +0000 Default: *******************************************************
2014-10-28 22:29:31 +0000 Default: OUTPUT_JSON:
{"output":{"output":"alert: “myApp” Would Like to Send You Notifications"},"last_index":4}
END_OUTPUT
2014-10-28 22:29:31 +0000 Default: *******************************************************
2014-10-28 22:29:31 +0000 Debug: target.frontMostApp().alert().buttons()["OK"].tap()
2014-10-28 22:31:34 +0000 Stopped: Script was stopped by the user
Instruments Trace Complete (Duration : 150.066040s; Output : /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141028-29391-pqpxgz/trace.trace)

Further analysis

@jmoody

@JaniJegoroff Can you try reading and writing your notification settings to alternative .plist? If you cannot reproduce the timeout, we'll know that there is some issue with UIAutomation's preferences API not playing nice with NSUserDefaults.

I changed app implementation so that it saves notification settings to .plist instead of NSUserDefault. In spite of that I can still reproduce the issue every time.

Is there any chance that problem is related to system level alert views that Calabash is dismissing automatically? Is there way to tell Calabash NOT to dismiss those alerts views, "allow push notifications" in this case, since I would like to see behaviour when we just ignore system level alert views?
@JaniJegoroff JaniJegoroff mentioned this issue Oct 30, 2014
Closed
@krukow
Copy link
Contributor

krukow commented Oct 30, 2014

@JaniJegoroff this is great. We're working on this issue.

I still would be a lot faster if I could access to an app where this reproduces, including source-code level access. Would it be possible to create a new app and create similar logic/behaviour to your app to reproduce it in a minimal context you can share?

@jmoody
Copy link
Contributor

jmoody commented Oct 30, 2014

Is there any chance that problem is related to system level alert views that Calabash is dismissing automatically? Is there way to tell Calabash NOT to dismiss those alerts views, "allow push notifications" in this case, since I would like to see behaviour when we just ignore system level alert views?

AFAICT, it is not possible to tell calabash not to dismiss those alerts. Please file an issue in https://github.com/calabash/run_loop/issues

I am not sure yet how we will be able to distinguish these APNS alerts from other alerts.

@JaniJegoroff JaniJegoroff mentioned this issue Oct 30, 2014
Closed
@JaniJegoroff
Copy link
Author

@krukow

@JaniJegoroff this is great. We're working on this issue.
I still would be a lot faster if I could access to an app where this reproduces, including source-code level access. Would it be possible to create a new app and create similar logic/behaviour to your app to reproduce it in a minimal context you can share?

Unfortunately, creating a new app with similar logic is out of my skills set. :( I'm going to need help from our dev's but it will go to the next week. Meanwhile, I'm trying to find a simpler way (not involving APNS) to reproduce.

@jmoody
Copy link
Contributor

jmoody commented Oct 30, 2014

@JaniJegoroff

Can you try this change in your relaunch method args:

    launch_options =
          {
                :uia_strategy => :host,
          }
    launcher.relaunch(launch_options)

The :preference strategy (AKA fast UIA) uses the UIAutomation preferences API to read requests and write results. Historically it has been must faster that the alternative strategy :host. The :host strategy (AKA host/cat), uses the UIAutomation API to read requests and write results to a file on the host machine. In previous versions of Xcode, the underlying JavaScript call performTaskWithPathArgumentsTimeout was throttled (by Apple) to one call per second.

Both strategies were more-or-less broken during the Xcode 6 betas. The :preferences strategy stabilized for Xcode 6.0.1, but it looks like it has become unstable in Xcode 6.1 targeting iOS 8.1 Simulators when client application use NSUserDefaults. I can't, for example, reproduce this problem in Xcode 6.1 with iOS 7.1 Simulators.

jmoody/calabash-ios-example#5

+1 for the bug report.

@jmoody jmoody changed the title Intermitted timeouts in Xcode 6.1 Intermittent timeouts performing gestures in Xcode 6.1 targeting iOS 8.1 simulators Oct 30, 2014
@JaniJegoroff
Copy link
Author

@jmoody - :host strategy works in my case. I also noticed that system level alert views are ignored in this mode.

Debug trace

Janis-Air:myApp janijegoroff$ DEBUG=1 DEBUG_HTTP=1 cucumber -p dev_ipad --tags @accept_notifications
Using the dev_ipad, sim_ipad_retina_81, reset, features, tags_default_ipad, tags_ci, tags_ipad and tags_skip_pending profiles...
@notifications @ci @ipad @iphone
Feature: Notifications
  As a User
  I have an option to accept or decline notification when new content is published
  So that I can control notifications

  @accept_notifications
  Scenario: Accept notifications          # Calabash/features/notifications.feature:20

INFO: Using uia strategy: 'host'
Sending 'QUIT' to instruments process '45919'
Waiting for instruments '45919' to terminate
Sending 'QUIT' to instruments process '46540'
Waiting for instruments '46540' to terminate
Preparation took 6.964111 seconds
{
                        :app => "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app",
                       :args => [],
    :bundle_dir_or_bundle_id => "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app",
                  :bundle_id => "myBundleId",
                     :device => "iphone",
              :device_target => "iPad Retina (8.1 Simulator)",
              :launch_method => :instruments,
             :launch_retries => 5,
                   :log_file => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/run_loop.out",
                  :no_launch => false,
                    :no_stop => false,
                      :reset => true,
                :results_dir => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w",
          :results_dir_trace => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/trace",
                     :script => "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/_run_loop.js",
                :sdk_version => nil,
                       :udid => "iPad Retina (8.1 Simulator)",
               :uia_strategy => :host,
                      :xcode => "6.1",
                 :xcode_path => "/Applications/Xcode61/Xcode.app/Contents/Developer"
}

### Starting on iPad Retina (8.1 Simulator) App: /Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app ###
2014-10-30 16:42:13 +0000 xcrun instruments -w "iPad Retina (8.1 Simulator)" -D "/var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/trace" -t "Automation" "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app" -e UIARESULTSPATH /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w -e UIASCRIPT /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/_run_loop.js  &> /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/run_loop.out
Launching took 12.253572 seconds
= Request

! CONNECT TO localhost:37265
! CONNECTION ESTABLISHED
POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:25 GMT
Content-Length: 83
Host: localhost:37265

{"query":null,"operation":{"method_name":"orientation","arguments":["status_bar"]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 72
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:25 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"down","results":["down"],"outcome":"SUCCESS"}= Request

POST /play HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:25 GMT
Content-Length: 135
Host: localhost:37265

{"events":"YnBsaXN0MDChAdMCBAYDBQdURGF0YUQDAAAAoFRUaW1lEwAAAbhNBUVUVFR5cGUQ
MggKERYcISovAAAAAAAAAQEAAAAAAAAACAAAAAAAAAAAAAAAAAAAADE=
"}

= Response

HTTP/1.1 200 OK
Transfer-Encoding: chunked
Accept-Ranges: bytes
Date: Thu, 30 Oct 2014 16:42:25 GMT

22
{"results":[],"outcome":"SUCCESS"}
0

= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:25 GMT
Content-Length: 93
Host: localhost:37265

{"query":"view marked:'homeLaunchButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 484
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:25 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"Main menu","selected":false,"enabled":true,"id":null,"rect":{"center_x":512,"y":174,"width":540,"x":242,"center_y":196,"height":44},"label":"homeLaunchButton","description":"<QTableViewCell: 0x78e25140; baseClass = UITableViewCell; frame = (0 100; 540 44); text = 'Main menu'; autoresize = W; layer = <CALayer: 0x78e25110>>","alpha":1,"class":"QTableViewCell","frame":{"y":100,"width":540,"x":0,"height":44}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:28 GMT
Content-Length: 93
Host: localhost:37265

{"query":"view marked:'homeLaunchButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 484
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:28 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"Main menu","selected":false,"enabled":true,"id":null,"rect":{"center_x":512,"y":174,"width":540,"x":242,"center_y":196,"height":44},"label":"homeLaunchButton","description":"<QTableViewCell: 0x78e25140; baseClass = UITableViewCell; frame = (0 100; 540 44); text = 'Main menu'; autoresize = W; layer = <CALayer: 0x78e25110>>","alpha":1,"class":"QTableViewCell","frame":{"y":100,"width":540,"x":0,"height":44}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 196}')
Result
{"status"=>"success", "value"=>true, "index"=>1}
= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:30 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:30 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:31 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:31 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:31 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:31 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:31 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:31 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:32 GMT
Content-Length: 79
Host: localhost:37265

{"query":"UICollectionView","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 607
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:32 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UICollectionView: 0x798f5000; frame = (0 0; 1024 768); clipsToBounds = YES; gestureRecognizers = <NSArray: 0x7a0258b0>; animations = { opacity=<CABasicAnimation: 0x7a020f10>; }; layer = <CALayer: 0x7a020720>; contentOffset: {0, -64}; contentSize: {1022, 1246}> collection view layout: <SUSPhotoReelFlowLayout: 0x78f83f20>","id":null,"label":null,"alpha":1,"class":"UICollectionView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:33 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:33 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x78e0ebb0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x78e07d30>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:33 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:33 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x78e0ebb0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x78e07d30>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:36 GMT
Content-Length: 125
Host: localhost:37265

{"query":"view marked:'homeHeroCell' label {text CONTAINS[cd] 'popular'}","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 477
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:36 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"text":"POPULAR","enabled":true,"rect":{"center_x":255,"y":632.5,"width":488,"x":11,"center_y":643.25,"height":21.5},"id":null,"description":"<UILabel: 0x78e0ebb0; frame = (5 122.5; 488 21.5); text = 'POPULAR'; opaque = NO; autoresize = RM+BM; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x78e07d30>>","label":"POPULAR","alpha":1,"class":"UILabel","frame":{"y":122.5,"width":488,"x":5,"height":21.5}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 255, :y 643.25}')
Result
{"status"=>"success", "value"=>true, "index"=>2}
= Request

POST /userprefs HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:38 GMT
Content-Length: 53
Host: localhost:37265

{"key":"NOTIFICATION_SCREEN_PRESENTED_KEY","value":1}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 37
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:38 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"results":[1,1],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:38 GMT
Content-Length: 93
Host: localhost:37265

{"query":"navigationItemButtonView first","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 528
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:38 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":false,"rect":{"center_x":38,"y":26,"width":52,"x":12,"center_y":41,"height":30},"description":"<UINavigationItemButtonView: 0x7a662c70; frame = (12 6; 52 30); opaque = NO; userInteractionEnabled = NO; animations = { opacity=<CABasicAnimation: 0x7a665340>; position=<CABasicAnimation: 0x7a6653f0>; }; layer = <CALayer: 0x7a662b40>>","id":null,"label":"Back","alpha":1,"class":"UINavigationItemButtonView","frame":{"y":6,"width":52,"x":12,"height":30}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 38, :y 41}')
Result
{"status"=>"success", "value"=>true, "index"=>3}
= Request

POST /userprefs HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:39 GMT
Content-Length: 53
Host: localhost:37265

{"key":"NOTIFICATION_SCREEN_PRESENTED_KEY","value":1}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 37
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:39 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"results":[1,1],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:39 GMT
Content-Length: 84
Host: localhost:37265

{"query":"view:'SUSLoadingView'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:39 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:39 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:39 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:40 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 445
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:40 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UIView: 0x7a1adda0; frame = (0 0; 1024 768); autoresize = W+H; animations = { position=<CASpringAnimation: 0x7a027570>; }; layer = <CALayer: 0x7a1b3010>>","id":"notificationScreen","label":null,"alpha":1,"class":"UIView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:40 GMT
Content-Length: 84
Host: localhost:37265

{"query":"view:'SUSLoadingView'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:40 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:40 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 445
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:40 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"enabled":true,"rect":{"center_x":512,"y":0,"width":1024,"x":0,"center_y":384,"height":768},"description":"<UIView: 0x7a1adda0; frame = (0 0; 1024 768); autoresize = W+H; animations = { position=<CASpringAnimation: 0x7a027570>; }; layer = <CALayer: 0x7a1b3010>>","id":"notificationScreen","label":null,"alpha":1,"class":"UIView","frame":{"y":0,"width":1024,"x":0,"height":768}}],"outcome":"SUCCESS"}    Given Notification screen is opened   # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:40 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'sureButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:40 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"sureButton","description":"<UIButton: 0x7a01e780; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7a73c040>>","label":"Sure","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:43 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'sureButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:43 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"sureButton","description":"<UIButton: 0x7a01e780; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7a73c040>>","label":"Sure","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 578}')
Result
{"status"=>"success", "value"=>true, "index"=>4}
= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:44 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'nextButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:44 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"nextButton","description":"<UIButton: 0x7a016c60; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7a0cbbb0>>","label":"Next","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:47 GMT
Content-Length: 87
Host: localhost:37265

{"query":"view marked:'nextButton'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 442
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:47 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[{"selected":false,"enabled":true,"rect":{"center_x":512,"y":553,"width":200,"x":412,"center_y":578,"height":50},"id":"nextButton","description":"<UIButton: 0x7a016c60; frame = (412 489; 200 50); clipsToBounds = YES; opaque = NO; autoresize = RM+BM; layer = <CALayer: 0x7a0cbbb0>>","label":"Next","alpha":1,"class":"UIButton","frame":{"y":489,"width":200,"x":412,"height":50}}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 512, :y 578}')
Result
{"status"=>"success", "value"=>true, "index"=>5}
    When I accept notifications           # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
= Request

POST /map HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:49 GMT
Content-Length: 95
Host: localhost:37265

{"query":"view marked:'notificationScreen'","operation":{"method_name":"query","arguments":[]}}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 67
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:49 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{"status_bar_orientation":"right","results":[],"outcome":"SUCCESS"}    Then Notification screen is dismissed # cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:47
= Request

POST /exit HTTP/1.1
Content-Type: application/x-www-form-urlencoded
User-Agent: HTTPClient/1.0 (2.3.4.1, ruby 2.1.2 (2014-05-08))
Accept: */*
Date: Thu, 30 Oct 2014 16:42:49 GMT
Content-Length: 78
Host: localhost:37265

{"post_resign_active_delay":0.4,"post_will_terminate_delay":0.4,"exit_code":0}

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Origin: *
Content-Length: 2
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Date: Thu, 30 Oct 2014 16:42:49 GMT
Accept-Ranges: bytes
Access-Control-Max-Age: 3000

{}Sending 'QUIT' to instruments process '45919'
Waiting for instruments '45919' to terminate
Sending 'QUIT' to instruments process '46540'
Waiting for instruments '46540' to terminate
Sending 'QUIT' to instruments process '59174'
Could not kill process '59174' - ignoring No such process
Waiting for instruments '59174' to terminate

1 scenario (1 passed)
3 steps (3 passed)
0m50.555s

run_loop.out

Janis-Air:myApp janijegoroff$ cat /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/run_loop.out
Waiting for device to boot...
2014-10-30 16:42:24 +0000 Default: OUTPUT_JSON:
{"output":"Starting loop"}
END_OUTPUT
2014-10-30 16:42:24 +0000 Default: *******************************************************
2014-10-30 16:42:25 +0000 Default: OUTPUT_JSON:
{"output":"Execute: UIALogger.logMessage('Listening for run loop commands');\n","last_index":0}
END_OUTPUT
2014-10-30 16:42:25 +0000 Default: *******************************************************
2014-10-30 16:42:25 +0000 Default: Listening for run loop commands
2014-10-30 16:42:25 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":0}
END_OUTPUT
2014-10-30 16:42:25 +0000 Default: *******************************************************
2014-10-30 16:42:30 +0000 Default: OUTPUT_JSON:
{"output":"Execute: uia.tapOffset('{:x 512, :y 196}')\n","last_index":1}
END_OUTPUT
2014-10-30 16:42:30 +0000 Default: *******************************************************
2014-10-30 16:42:30 +0000 Debug: target.tapWithOptions({x:"512", y:"196"}, )
2014-10-30 16:42:30 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":1}
END_OUTPUT
2014-10-30 16:42:30 +0000 Default: *******************************************************
2014-10-30 16:42:38 +0000 Default: OUTPUT_JSON:
{"output":"Execute: uia.tapOffset('{:x 255, :y 643.25}')\n","last_index":2}
END_OUTPUT
2014-10-30 16:42:38 +0000 Default: *******************************************************
2014-10-30 16:42:38 +0000 Debug: target.tapWithOptions({x:"255", y:"643.25"}, )
2014-10-30 16:42:38 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":2}
END_OUTPUT
2014-10-30 16:42:38 +0000 Default: *******************************************************
2014-10-30 16:42:39 +0000 Default: OUTPUT_JSON:
{"output":"Execute: uia.tapOffset('{:x 38, :y 41}')\n","last_index":3}
END_OUTPUT
2014-10-30 16:42:39 +0000 Default: *******************************************************
2014-10-30 16:42:39 +0000 Debug: target.tapWithOptions({x:"38", y:"41"}, )
2014-10-30 16:42:39 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":3}
END_OUTPUT
2014-10-30 16:42:39 +0000 Default: *******************************************************
2014-10-30 16:42:44 +0000 Default: OUTPUT_JSON:
{"output":"Execute: uia.tapOffset('{:x 512, :y 578}')\n","last_index":4}
END_OUTPUT
2014-10-30 16:42:44 +0000 Default: *******************************************************
2014-10-30 16:42:44 +0000 Debug: target.tapWithOptions({x:"512", y:"578"}, )
2014-10-30 16:42:44 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":4}
END_OUTPUT
2014-10-30 16:42:44 +0000 Default: *******************************************************
2014-10-30 16:42:49 +0000 Default: OUTPUT_JSON:
{"output":"Execute: uia.tapOffset('{:x 512, :y 578}')\n","last_index":5}
END_OUTPUT
2014-10-30 16:42:49 +0000 Default: *******************************************************
2014-10-30 16:42:49 +0000 Debug: target.tapWithOptions({x:"512", y:"578"}, )
2014-10-30 16:42:49 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":5}
END_OUTPUT
2014-10-30 16:42:49 +0000 Default: *******************************************************
2014-10-30 16:42:50 +0000 Fail: The target application appears to have died
Instruments Trace Complete (Duration : 33.906391s; Output : /var/folders/66/62hrz8650r72_srksbdfwpjm0000gn/T/run_loop20141030-58470-uuq33w/trace.trace)
Janis-Air:myApp janijegoroff$

@robsteinde
Copy link

@jmoody - :host strategy works in my case too.

Debug trace looks nearly the same, so I don't paste it.

@axhossain
Copy link

I am also getting timeout, not sure if this is related to this same case...

Feature: Ensure Case Conversation actions

Scenario: Add a note to case # features/case_conversation.feature:3
Given I am signed into the application # features/step_definitions/generic_steps.rb:11
Timeout waiting for elements: UIWebView css:'.nomargin-bottom' (Calabash::Cucumber::WaitHelpers::WaitError)
./features/step_definitions/generic_steps.rb:20:in /^I am signed into the application$/' features/case_conversation.feature:4:inGiven I am signed into the application'
And I go to the conversation view of a case # features/step_definitions/case_detail_steps.rb:1
Then I should be able to add a note to the case # features/step_definitions/case_conversation_steps.rb:1
Couldn't find the Menu button (Calabash::Cucumber::WaitHelpers::WaitError)
/Users/ahossain/.rvm/gems/ruby-2.1.2/gems/calabash-cucumber-0.11.0/lib/calabash-cucumber/wait_helpers.rb:404:in screenshot_and_retry' /Users/ahossain/.rvm/gems/ruby-2.1.2/gems/calabash-cucumber-0.11.0/lib/calabash-cucumber/wait_helpers.rb:111:inrescue in wait_for'
/Users/ahossain/.rvm/gems/ruby-2.1.2/gems/calabash-cucumber-0.11.0/lib/calabash-cucumber/wait_helpers.rb:102:in wait_for' /Users/ahossain/.rvm/gems/ruby-2.1.2/gems/calabash-cucumber-0.11.0/lib/calabash-cucumber/wait_helpers.rb:156:inwait_poll'
/Users/ahossain/Desktop/github/Regression-suite/features/ios/pages/case_filter_screen.rb:40:in find_menu_icon' /Users/ahossain/Desktop/github/Regression-suite/features/step_definitions/login_steps.rb:79:in/^I log out of the app$/'
/Users/ahossain/.rvm/gems/ruby-2.1.2/gems/cucumber-1.3.17/lib/cucumber/core_ext/instance_exec.rb:36:in cucumber_instance_exec' /Users/ahossain/.rvm/gems/ruby-2.1.2/gems/cucumber-1.3.17/lib/cucumber/rb_support/rb_step_definition.rb:97:ininvoke'
/Users/ahossain/.rvm/gems/ruby-2.1.2/gems/cucumber-1.3.17/lib/cucumber/step_match.rb:25:in invoke' /Users/ahossain/.rvm/gems/ruby-2.1.2/gems/cucumber-1.3.17/lib/cucumber/runtime/support_code.rb:60:ininvoke'
/Users/ahossain/.rvm/gems/ruby-2.1.2/gems/cucumber-1.3.17/lib/cucumber/rb_support/rb_world.rb:52:in step' /Users/ahossain/Desktop/github/Regression-suite/features/support/global_hooks.rb:2:inAfter'

@jmoody
Copy link
Contributor

jmoody commented Oct 30, 2014

@axhossain Yours is an unrelated problem. #550

@ark-konopacki
Copy link
Contributor

@jmoody :host strategy works in my case too.
Environment
Xcode 6.1
Calabash 0.11.3
7.1 and 8.1 sim

@robsteinde
Copy link

@jmoody with :host strategy another deterministic timeout occurs with uia.typeString.
It's only in one single case in my large app. I tried to get the reason why it times out here and not in all the other places where text is typed, but didn't get it. The only difference is, that it's in an UIPopoverController, but I couldn't reproduce it in an test app :-(
Just one hint: It's not dying, if I increase timeout to wait in run-loop core at send_command, the answer arrives after 90-100 seconds. --> Spooky

@krukow krukow mentioned this issue Nov 3, 2014
Merged
@krukow
Copy link
Contributor

krukow commented Nov 3, 2014

For those experiencing this issue could you try

0.11.4.pre1 (both client, server and run_loop updates)

NOTE: this doesn't not fix issues related to push notifications and timeouts.

@krukow
Copy link
Contributor

krukow commented Nov 3, 2014

Please report back here.

@jmoody
Copy link
Contributor

jmoody commented Nov 4, 2014

I have merged Karl's fix into develop with a fix for iOS 7.1 simulators on Xcode 6.1.

This was referenced Nov 5, 2014
Merged
Merged
Closed
Merged
@krukow
Copy link
Contributor

krukow commented Nov 7, 2014

I've updated the sample app to use both location dialog and push notifications. Both are dismissed fine and the automation works.

@JaniJegoroff @nfrydenholm could you help reproducing the issue by making appropriate changes to this app:

https://github.com/calabash/calabash-ios-example

Note since this app adds Calabash server source code you must checkout the develop branch of

https://github.com/calabash/calabash-ios-server

into the folder:

../calabash-ios-server

(relative to where calabash-ios-example project is)

@JaniJegoroff
Copy link
Author

@krukow @jmoody
Awesome, thanks Karl! I made changes to example app:
https://github.com/JaniJegoroff/calabash-ios-example-issue-585

I found a way to reproduce issue every time. Could you give a try?

@krukow
Copy link
Contributor

krukow commented Nov 9, 2014

@JaniJegoroff thanks for doing the work. I was able to reproduce this consistently -- it is a race condition in UIAutomation. I will need to think about how to work around this. I have a couple of ideas.

@krukow
Copy link
Contributor

krukow commented Nov 9, 2014

@JaniJegoroff -- this is probably not the final solution since it slows down handling of alert views by a second or so, but could you try this as a workaround:

Use this version of run_loop (calabash/run_loop origin/workaround-preferences-write-issue)

Corresponding to:
calabash/run_loop#71

Rubygems is not allowing publishing right now, but I will publish tomorrow as run_loop 1.1.1.pre3.

When that happens and you want to test this - add in your Gemfile:

gem 'run_loop', '1.1.1.pre3'

@krukow
Copy link
Contributor

krukow commented Nov 9, 2014

cc: @nfrydenholm

@JaniJegoroff
Copy link
Author

@krukow Cool, I will check this tomorrow.

@krukow
Copy link
Contributor

krukow commented Nov 10, 2014

Pushed run_loop 1.1.1.pre3 to rubygems.org.

@JaniJegoroff
Copy link
Author

@krukow Good work, I can confirm that my scenarios are passing with run_loop 1.1.1pre3

@krukow
Copy link
Contributor

krukow commented Nov 10, 2014

Sounds good --- @jmoody FYI this is probably not our final solution as it will slow down the script in certain scenarios. So please don't merge this pull request.

@JaniJegoroff we will look at tweaking this solution so it avoids the slowdown but still works as expected.

@jmoody jmoody mentioned this issue Nov 13, 2014
Closed
@krukow krukow mentioned this issue Nov 23, 2014
Merged
3 tasks
@krukow
Copy link
Contributor

krukow commented Nov 24, 2014

@JaniJegoroff could you try also the version of server (0.11.5.pre1) here:

calabash/calabash-ios-server#97

combined with

#622

and

run_loop 1.1.1.pre4

cc: @nfrydenholm

@JaniJegoroff
Copy link
Author

@krukow - I executed my APNS scenario with following setup:
calabash 0.11.5.pre2 (client + server)
run_loop 1.1.1.pre4

No problems detected.

@krukow
Copy link
Contributor

krukow commented Nov 30, 2014

@JaniJegoroff thanks. I'm closing this issue!

@krukow krukow closed this as completed Nov 30, 2014
@nfrydenholm
Copy link

Sorry for not being active on this one - I just got back from a nice long vacation ;)
I'll catch up soon, and try the newest (pre) release to see if it works fine here as well.

@jmoody jmoody mentioned this issue Oct 16, 2015
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@krukow @jmoody @robsteinde @JaniJegoroff @axhossain @nfrydenholm @ark-konopacki