Intermittent 'Could not parse response '';' error when executing tap_mark command

[JaniJegoroff]

This is the new issue for intermitted RuntimeError: Could not parse response ''; the app has probably crashed error when executing tap_mark command. Issue was first referenced in the discussion: #566

Based on my experience issue happens more often in the iPhone 6 simulator than in iPad Retina simulator.

Environment
Xcode 6.1
Calabash 0.11.3
run_loop 1.0.9
8.1 simulators

Steps to reproduce:

1. Build your app to iPhone 6 (8.1 Simulator)
2. Launch DEBUG=1 DEBUG_HTTP=1 DEVICE_TARGET='iPhone 6 (8.1 Simulator)' calabash-ios console
3. Execute: start_test_server_in_background
4. Execute: tap_mark('<your-text>')

curl:

Janis-MacBook-Pro:~ 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":"git@github.com: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-MacBook-Pro:myApp janijegoroff$ DEBUG=1 DEBUG_HTTP=1 DEVICE_TARGET='iPhone 6 (8.1 Simulator)' calabash-ios console
Running irb...
irb(main):001:0> start_test_server_in_background

INFO: Using uia strategy: 'preferences'
Preparation took 2.502783 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 => "iPhone 6 (8.1 Simulator)",
              :launch_method => :instruments,
             :launch_retries => 5,
                   :log_file => "/var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/run_loop.out",
                  :no_launch => false,
                    :no_stop => false,
                      :reset => false,
                :results_dir => "/var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x",
          :results_dir_trace => "/var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/trace",
                     :script => "/var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/_run_loop.js",
                :sdk_version => nil,
                       :udid => "iPhone 6 (8.1 Simulator)",
               :uia_strategy => :preferences,
                      :xcode => "6.1",
                 :xcode_path => "/Applications/Xcode61/Xcode.app/Contents/Developer"
}

### Starting on iPhone 6 (8.1 Simulator) App: /Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app ###
2014-11-06 13:51:11 +0000 xcrun instruments -w "iPhone 6 (8.1 Simulator)" -D "/var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/trace" -t "Automation" "/Users/janijegoroff/Library/Developer/Xcode/DerivedData/myApp-civuqgdjemtasdaqyhpsrgakmnyv/Build/Products/Calabash-iphonesimulator/myApp.app" -e UIARESULTSPATH /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x -e UIASCRIPT /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/_run_loop.js  &> /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/run_loop.out
Launching took 5.528413 seconds
Calabash::Cucumber::Launcher: Launch Method instruments
Log file: /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/run_loop.out
irb(main):002:0> tap_mark 'Notification'
= 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, 06 Nov 2014 13:51:25 GMT
Content-Length: 89
Host: localhost:37265

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

= Response

HTTP/1.1 200 OK
Access-Control-Allow-Credentials: true
Access-Control-Allow-Methods: GET, POST, PUT, DELETE, OPTIONS
Access-Control-Max-Age: 3000
Accept-Ranges: bytes
Date: Thu, 06 Nov 2014 13:51:25 GMT
Content-Length: 478
Access-Control-Allow-Origin: *

{"status_bar_orientation":"down","results":[{"alpha":1,"enabled":true,"id":null,"frame":{"y":8,"x":16,"width":351,"height":27.5},"class":"UITableViewLabel","rect":{"y":328,"height":27.5,"center_y":341.75,"x":16,"center_x":191.5,"width":351},"label":"Notification","text":"Notification","description":"<UITableViewLabel: 0x7fdc615e9700; frame = (16 8; 351 27.5); text = 'Notification'; userInteractionEnabled = NO; layer = <_UILabelLayer: 0x7fdc615e8610>>"}],"outcome":"SUCCESS"}Sending UIA command
uia.tapOffset('{:x 191.5, :y 341.75}')
= 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: Thu, 06 Nov 2014 13:51:25 GMT
Content-Length: 52
Host: localhost:37265

{"command":"uia.tapOffset('{:x 191.5, :y 341.75}')"}

= Response

HTTP/1.1 200 OK
Date: Thu, 06 Nov 2014 13:51:25 GMT
Accept-Ranges: bytes
Transfer-Encoding: chunked

! CONNECTION CLOSED
RuntimeError: Could not parse response ''; the app has probably crashed
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/uia.rb:33:in `rescue in uia'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/uia.rb:30:in `uia'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/uia.rb:344:in `uia_handle_command'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/uia.rb:144:in `uia_tap_offset'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/actions/instruments_actions.rb:93:in `query_action'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/actions/instruments_actions.rb:15:in `touch'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/core.rb:1095:in `query_action_with_options'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/core.rb:174:in `touch'
    from /Users/janijegoroff/.rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/calabash-cucumber-0.11.3/lib/calabash-cucumber/core.rb:926:in `tap_mark'
    from (irb):2
    from /Users/janijegoroff/.rbenv/versions/2.1.2/bin/irb:11:in `<main>'
irb(main):003:0>

run_loop.out:

Janis-MacBook-Pro:myApp janijegoroff$ cat /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/run_loop.out
Waiting for device to boot...
2014-11-06 13:51:17 +0000 Default: OUTPUT_JSON:
{"status":"success","value":true,"index":0}
END_OUTPUT
2014-11-06 13:51:17 +0000 Default: ***********************************************************
2014-11-06 13:51:25 +0000 Default: index 0 is command: uia.tapOffset('{:x 191.5, :y 341.75}')
2014-11-06 13:51:25 +0000 Debug: target.tapWithOptions({x:"191.5", y:"341.75"}, )
2014-11-06 13:51:25 +0000 Default: Success: true
2014-11-06 13:51:25 +0000 Default: Write result...
2014-11-06 13:51:25 +0000 Default: Check successful storage...
2014-11-06 13:51:25 +0000 Default: Storage succeeded: 0
2014-11-06 13:51:28 +0000 Fail: The target application appears to have died
Instruments Trace Complete (Duration : 15.833581s; Output : /var/folders/02/2thphdms7yqcby08qk4vbbf80000gn/T/run_loop20141106-18284-1avuy9x/trace.trace)
Janis-MacBook-Pro:myApp janijegoroff$

[krukow]

@JaniJegoroff Can you try in version 0.11.4 since this is related to uia timeout errors. Is there a way for us to reproduce this? Does it reproduce deterministically?

[JaniJegoroff]

@krukow
I have been able to reproduce with version 0.11.4 as well. However, it's not easy to reproduce since it is so random. I was not able to reproduce in calabash-ios console anymore but running full test set it happened once.

Luckily, I have been also able to reproduce using calabash-ios-example project: https://github.com/JaniJegoroff/calabash-ios-example-issue-600

[krukow]

@JaniJegoroff I was able to reproduce it. However, In all cases it was real crashes in the app. It occurs in the sample when you delete a table cell in "Third" view.

Are you sure it is not the app you're testing that is crashing. Have you looked at the iOS Core Simulator logs to look for crash reports?

Nov  9 22:13:41 krukow.local LPSimpleExample-cal[5870]: *** Assertion failure in -[UITableView _endCellAnimationsWithContext:], /SourceCache/UIKit_Sim/UIKit-3318.16.14/UITableView.m:1582
Nov  9 22:13:41 krukow.local LPSimpleExample-cal[5870]: *** Terminating app due to uncaught exception 'NSInternalInconsistencyException', reason: 'Invalid update: invalid number of rows in section 0.  The number of rows contained in an existing section after the update (30) must be equal to the number of rows contained in that section before the update (30), plus or minus the number of rows inserted or deleted from that section (0 inserted, 1 deleted) and plus or minus the number of rows moved into or out of that section (0 moved in, 0 moved out).'
    *** First throw call stack:
    (
        0   CoreFoundation                      0x000000010653ef35 __exceptionPreprocess + 165
        1   libobjc.A.dylib                     0x0000000105bb0bb7 objc_exception_throw + 45
        2   CoreFoundation                      0x000000010653ed9a +[NSException raise:format:arguments:] + 106
        3   Foundation                          0x000000010517c5df -[NSAssertionHandler handleFailureInMethod:object:file:lineNumber:description:] + 195
        4   UIKit                               0x0000000103edcc2a -[UITableView _endCellAnimationsWithContext:] + 11746
        5   UIKit                               0x0000000115defabb -[UITableViewAccessibility deleteRowsAtIndexPaths:withRowAnimation:] + 48
        6   LPSimpleExample-cal                 0x000000010395a9c7 -[LPThirdViewController tableView:commitEditingStyle:forRowAtIndexPath:] + 151
        7   UIKit                               0x0000000103f00cb4 -[UITableView animateDeletionOfRowWithCell:] + 130
        8   UIKit                               0x0000000103ee1125 __52-[UITableView _swipeActionButtonsForRowAtIndexPath:]_block_invoke + 72
        9   UIKit                               0x0000000103e098be -[UIApplication sendAction:to:from:forEvent:] + 75
        10  UIKit                               0x0000000103f10410 -[UIControl _sendActionsForEvents:withEvent:] + 467
        11  UIKit                               0x0000000103f0f7df -[UIControl touchesEnded:withEvent:] + 522
        12  UIKit                               0x00000001041b6540 _UIGestureRecognizerUpdate + 9487
        13  UIKit                               0x0000000103e4eff6 -[UIWindow _sendGesturesForEvent:] + 1041
        14  UIKit                               0x0000000103e4fc23 -[UIWindow sendEvent:] + 667
        15  UIKit                               0x0000000103e1c9b1 -[UIApplication sendEvent:] + 246
        16  UIKit                               0x0000000103e29a7d _UIApplicationHandleEventFromQueueEvent + 17370
        17  UIKit                               0x0000000103e05103 _UIApplicationHandleEventQueue + 1961
        18  CoreFoundation                      0x0000000106474551 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
        19  CoreFoundation                      0x000000010646a41d __CFRunLoopDoSources0 + 269
        20  CoreFoundation                      0x0000000106469a54 __CFRunLoopRun + 868
        21  CoreFoundation                      0x0000000106469486 CFRunLoopRunSpecific + 470
        22  GraphicsServices                    0x00000001087e19f0 GSEventRunModal + 161
        23  UIKit                               0x0000000103e08420 UIApplicationMain + 1282
        24  LPSimpleExample-cal                 0x0000000103959827 main + 103
        25  libdyld.dylib                       0x0000000105f62145 start + 1
    )

[JaniJegoroff]

@krukow Ah, I see that now.

I found two kind of suspicious crash logs:

1. Application crashes that are related to transition animations
2. ScriptAgent crashes

Good thing is that after upgrading to Calabash version 0.11.4 (two days ago) I have not seen this issue in Jenkins test run anymore. Since upgrade, total ~400 scenarios have been executed in iPhone and iPad.

I think we can close this issue.

[jmoody]

Thanks @JaniJegoroff for investigating.

[praveenraj1987]

I see this issue on xcode 6.2, ios 8.2.
Could not parse response ''; the app has probably crashed (RuntimeError).

[fpena]

This issue still happens using XCode 6.3.2 and iOS 8.3.