waitForAngular() fails on angular-webapp (appium/protractor/chrome on real device)

transferring this from SO (http://stackoverflow.com/questions/26299173/protractors-waitforangular-fails-on-angular-webapp-appium-chrome-on-real-dev)

i’m (newly) using protractor to run e2e cucumber tests. i got a web-app
which is angularJS based. im using appium to remotely run the test on a
real android device. here the versions:

windows8.1
[email protected] (with submodule [email protected])
[email protected]
android device with 4.4.4

my protractor configuration (extracts), corresponding to https://github.com/angular/protractor/blob/master/docs/browser-setup.md:

currentDeviceUDID = (...);
var appToTestURL = 'http://my.website.com:9000/app/index.html';

exports.config = {
  seleniumAddress: 'http://localhost:4723/wd/hub';
  chromeOnly: false,
  specs: ['features/sample.feature'],

  capabilities: {
    browserName: 'chrome',
    'appium-version': '1.0',
    platformName: 'Android',
    platformVersion: '4.4.4',
    udid: currentDeviceUDID
  },

  baseUrl: appToTestURL

  framework: 'cucumber',
  cucumberOpts: {
    require: 'features/stepDefinitionsSample.js',
    tags: '@dev',
    format: 'progress'
  },

  // configuring wd in onPrepare
 onPrepare: function () {
    var wd = require('wd'),
    protractor = require('protractor'),
    wdBridge = require('wd-bridge')(protractor, wd);
    wdBridge.initFromProtractor(exports.config);
  },

  allScriptsTimeout: 30000,
  getPageTimeout: 30000
};

as you can see, i have replaced the protractor’s webdriver url with
the appium webdriver. i start the appium from commandline with “appium
&”, then i run the test with “protactor cucumbertest.conf”

the phone opens chrome browser and navigates to the url i give it with “browser.get(url)”

the problem is the following:
the call waitForAngular(), which is asynchronously waiting for the
website to load and on all open http request (as far as i understand),
is not executed sucessfully on the phone. the phone does not react to
the call, and the webdriver proxy returns a 500 after the timeout interval.

corresponding to https://github.com/angular/protractor/issues/1358, i understood that the waitForAngular() function is mixed in protractor into the calls

['getCurrentUrl', 'getPageSource', 'getTitle'];

behind waitForAngular() in the file protractor.js is the function below, which is proxied to the phone:

functions.waitForAngular = function(selector, callback) {
  var el = document.querySelector(selector);
  try {
    if (angular.getTestability) {
      angular.getTestability(el).whenStable(callback);
    } else {
      angular.element(el).injector().get('$browser').
      notifyWhenNoOutstandingRequests(callback);
    }
  } catch (e) {
    callback(e);
  }
};

additional information: when i stimulate an error on the webdriver
(browser) object, the error message points to the chromedriver.exe
inside the protractor directory. i dont understand why the error is not
from appium’s chromedriver

without the successful call waitForAngular, i cannot (stable or at all)
access elements on the page on the phone, so not testing. maybe im
misunderstanding some fundamental configuration detail here, all hints
are welcome.

appium server log:

info: --> POST /wd/hub/session {"desiredCapabilities":{"browserName":"chrome","appium-version":"1.0","platformName":"Android","platformVersion":"4.4.4","deviceName":"Xperia Z","udid":"0482067d5fXXXXX","count":1}}
info: [debug] The following desired capabilities were provided, but not recognized by appium. They will be passed on to any other services running on this server. : appium-version, count
info: Set mode: Proxying straight through to Chromedriver
info: [debug] Looks like we want chrome on android
info: [debug] Creating new appium session eec8a96d-ed2a-4e80-995e-6950bc59b1b1
info: [debug] Preparing device for session
info: [debug] Not checking whether app is present since we are assuming it's already on the device
info: [debug] Checking whether adb is present
info: [debug] Using adb from C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe
info: Retrieving device
info: [debug] Trying to find a connected android device
info: [debug] Getting connected devices...
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" devices
info: [debug] 1 device(s) connected
info: Found device 0482067d5fXXXXX
info: [debug] Setting device id to 0482067d5fXXXXX
info: [debug] Waiting for device to be ready and to respond to shell commands (timeout = 5)
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX wait-for-device
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX shell "echo 'ready'"
info: [debug] Starting logcat capture
info: [debug] Pushing unlock helper app to device...
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX install "C:\Users\myusername\AppData\Roaming\npm\node_modules\appium\build\unlock_apk\unlock_apk-debug.apk"
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX shell "dumpsys window"
info: [debug] Writing dumpsys output to C:\Users\myusername\AppData\Roaming\npm\node_modules\appium\.dumpsys.log
info: [debug] Screen already unlocked, continuing.
info: [debug] Forwarding system:4724 to device:4724
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX forward tcp:4724 tcp:4724
info: [debug] Pushing appium bootstrap to device...
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX push "C:\\Users\\myusername\\AppData\\Roaming\\npm\\node_modules\\appium\\build\\android_bootstrap\\AppiumBootstrap.jar" /data/local/tmp/
info: Starting App
info: [debug] Attempting to kill all 'uiautomator' processes
info: [debug] Getting all processes with 'uiautomator'
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX shell "ps 'uiautomator'"
info: [debug] No matching processes found
info: [debug] Running bootstrap
info: [debug] spawning: C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe -s 0482067d5fXXXXX shell uiautomator runtest AppiumBootstrap.jar -c io.appium.android.bootstrap.Bootstrap
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: numtests=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=
info: [debug] [UIAUTOMATOR STDOUT] io.appium.android.bootstrap.Bootstrap:
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: current=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: 1
info: [debug] [BOOTSTRAP] [debug] Socket opened on port 4724
info: [debug] [BOOTSTRAP] [debug] Appium Socket Server Ready
info: [debug] [BOOTSTRAP] [debug] Loading json...
info: [debug] Pushing command to appium work queue: ["getDataDir",{}]
info: [debug] [BOOTSTRAP] [debug] Registered crash watchers.
info: [debug] [BOOTSTRAP] [debug] Client connected
info: [debug] [BOOTSTRAP] [debug] Got data from client: {"cmd":"action","action":"getDataDir","params":{}}
info: [debug] [BOOTSTRAP] [debug] Got command of type ACTION
info: [debug] [BOOTSTRAP] [debug] Got command action: getDataDir
info: [debug] [BOOTSTRAP] [debug] Returning result: {"value":"\/data\/local\/tmp","status":0}
info: [debug] dataDir set to: /data/local/tmp
info: [debug] Creating Chrome session
info: [debug] Set chromedriver binary as: C:\Users\myusername\AppData\Roaming\npm\node_modules\appium\build\chromedriver\windows\chromedriver.exe
info: [debug] Ensuring Chromedriver exists
info: [debug] Killing any old chromedrivers, running: FOR /F "usebackq tokens=5" %a in (`netstat -nao ^| findstr /R /C:"9515 "`) do (FOR /F "usebackq" %b in (`TASKLIST /FI "PID eq %a" ^| findstr /I chromedriver.exe`) do (IF NOT %b=="" TASKKILL /F /PID %b))
info: [debug] No old chromedrivers seemed to exist
info: [debug] Spawning chromedriver with: C:\Users\myusername\AppData\Roaming\npm\node_modules\appium\build\chromedriver\windows\chromedriver.exe
info: [debug] [CHROMEDRIVER] Starting ChromeDriver (v2.10.267521) on port 9515
Only local connections are allowed.
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session","method":"POST","json":{"sessionId":null,"desiredCapabilities":{"chromeOptions":{"androidPackage":"com.android.chrome","androidDeviceSerial":"0482067d5fXXXXX"}}}}
info: [debug] Successfully started chrome session 9c4c76e1bdc1d4de5a3449e9b11d8a9c
info: [debug] Overriding session id with "9c4c76e1bdc1d4de5a3449e9b11d8a9c"
info: [debug] Device launched! Ready for commands
info: [debug] Setting command timeout to the default of 60 secs
info: [debug] Appium session started with sessionId 9c4c76e1bdc1d4de5a3449e9b11d8a9c
info: <-- POST /wd/hub/session 303 11732.464 ms - 9
info: --> GET /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c {}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c","method":"GET"}
info: [debug] Proxied response received with status 200: "{\"sessionId\":\"9c4c76e1bdc1d4de5a3449e9b11d8a9c\",\"status\":0,\"value\":{\"acceptSslCerts\":true,\"applicationCacheEnabled\":false,\"browserConnectionEnabled\":false,\"browserName\":\"chrome\",\"chrome\":{},\"cssSelectorsEnabled\":true,\"databaseEnabled\":false,\"handlesAlerts\":true,\"javascriptEnabled\":true,\"locationContextEnabled\":true,\"nativeEvents\":true,\"platform\":\"ANDROID\",\"rotatable\":false,\"takesHeapSnapshot\":true,\"takesScreenshot\":true,\"version\":\"37.0.2062.117\",\"webStorageEnabled\":true}}"
info: <-- GET /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c 200 3.335 ms - 476
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/timeouts/async_script {"ms":61000}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/timeouts/async_script","method":"POST","json":{"ms":61000}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":null}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/timeouts/async_script 200 3.650 ms - 72
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/url {"url":"data:text/html,<html></html>"}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/url","method":"POST","json":{"url":"data:text/html,<html></html>"}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":null}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/url 200 279.854 ms - 72
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute {"script":"window.name = \"NG_DEFER_BOOTSTRAP!\" + window.name;window.location.replace(\"http://my.website.com:9000/app/index.html\");","args":[]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute","method":"POST","json":{"script":"window.name = \"NG_DEFER_BOOTSTRAP!\" + window.name;window.location.replace(\"http://my.website.com:9000/app/index.html\");","args":[]}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":null}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute 200 4684.740 ms - 72
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute {"script":"return window.location.href;","args":[]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute","method":"POST","json":{"script":"return window.location.href;","args":[]}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":"http://my.website.com:9000/app/index.html"}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute 200 23.030 ms - 109
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async {"script":"try { return (function (attempts, asyncCallback) {\n  var callback = function(args) {\n    setTimeout(function() {\n      asyncCallback(args);\n    }, 0);\n  };\n  var check = function(n) {\n    try {\n      if (window.angular && window.angular.resumeBootstrap) {\n        callback([true, null]);\n      } else if (n < 1) {\n        if (window.angular) {\n          callback([false, 'angular never provided resumeBootstrap']);\n        } else {\n          callback([false, 'retries looking for angular exceeded']);\n        }\n      } else {\n        window.setTimeout(function() {check(n - 1);}, 1000);\n
    }\n    } catch (e) {\n      callback([false, e]);\n    }\n  };\n  check(attempts);\n}).apply(this, arguments); }\ncatch(e) { throw (e instanceof Error) ? e : new Error(e); }","args":[30]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async","method":"POST","json":{"script":"try { return (function (attempts, asyncCallback) {\n  var callback = function(args) {\n    setTimeout(function() {\n      asyncCallback(args);\n    }, 0);\n  };\n  var check = function(n) {\n    try {\n      if (window.angular && window.angular.resumeBootstrap) {\n        callback([true, null]);\n      } else if (n < 1) {\n        if (window.angular) {\n          callback([false, 'angular never provided resumeBootstrap']);\n        } else {\n          callback([false, 'retries looking for angular exceeded']);\n
}\n      } else {\n        window.setTimeout(function() {check(n - 1);}, 1000);\n      }\n    } catch (e) {\n      callback([false, e]);\n    }\n  };\n  check(attempts);\n}).apply(this, arguments); }\ncatch(e) { throw (e instanceof Error) ? e : new Error(e); }","args":[30]}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":[true,null]}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async 200 109.826 ms - 79
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute {"script":"return (function () {\n    angular.module('protractorBaseModule_', []).\n        config(['$compileProvider', function($compileProvider) {\n
if ($compileProvider.debugInfoEnabled) {\n            $compileProvider.debugInfoEnabled(true);\n          }\n
 }]);\n  }).apply(null, arguments);","args":[]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute","method":"POST","json":{"script":"return (function () {\n    angular.module('protractorBaseModule_', []).\n        config(['$compileProvider', function($compileProvider) {\n          if ($compileProvider.debugInfoEnabled) {\n            $compileProvider.debugInfoEnabled(true);\n          }\n        }]);\n  }).apply(null, arguments);","args":[]}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":null}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute 200 18.411 ms - 72
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute {"script":"angular.resumeBootstrap(arguments[0]);","args":[["protractorBaseModule_"]]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute","method":"POST","json":{"script":"angular.resumeBootstrap(arguments[0]);","args":[["protractorBaseModule_"]]}}
info: [debug] Proxied response received with status 200: {"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c","status":0,"value":null}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute 200 1573.851 ms - 72
info: --> POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async {"script":"try { return (function (selector, callback) {\n  var el = document.querySelector(selector);\n  try {\n    if (angular.getTestability) {\n
angular.getTestability(el).whenStable(callback);\n    } else {\n      angular.element(el).injector().get('$browser').\n          notifyWhenNoOutstandingRequests(callback);\n    }\n  } catch (e) {\n    callback(e);\n  }\n}).apply(this, arguments); }\ncatch(e) { throw (e instanceof Error) ? e : new Error(e); }","args":["body"]}
info: [debug] Proxying command to 127.0.0.1:9515
info: [debug] Making http request with opts: {"url":"http://127.0.0.1:9515/wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async","method":"POST","json":{"script":"try { return (function (selector, callback) {\n  var el = document.querySelector(selector);\n  try {\n    if (angular.getTestability) {\n      angular.getTestability(el).whenStable(callback);\n    } else {\n      angular.element(el).injector().get('$browser').\n          notifyWhenNoOutstandingRequests(callback);\n    }\n  } catch (e) {\n    callback(e);\n  }\n}).apply(this, arguments); }\ncatch(e) { throw (e instanceof Error) ? e : new Error(e); }","args":["body"]}}
info: [debug] Didn't get a new command in 60 secs, shutting down...
info: Shutting down appium session
info: [debug] [BOOTSTRAP] [debug] Got data from client: {"cmd":"shutdown"}
info: [debug] [BOOTSTRAP] [debug] Got command of type SHUTDOWN
info: [debug] [BOOTSTRAP] [debug] Returning result: {"value":"OK, shutting down","status":0}
info: [debug] Sent shutdown command, waiting for UiAutomator to stop...
info: [debug] [BOOTSTRAP] [debug] Closed client connection
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: numtests=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=.
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: current=1
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: 0
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=
info: [debug] [UIAUTOMATOR STDOUT] Test results for WatcherResultPrinter=.
info: [debug] [UIAUTOMATOR STDOUT] Time: 73.673
info: [debug] [UIAUTOMATOR STDOUT] OK (1 test)
info: [debug] [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: -1
info: [debug] UiAutomator shut down normally
info: [debug] Killing chromedriver
info: [debug] Responding to client with error: {"status":13,"value":{"message":"An unknown server-side error occurred while processing the command.","origValue":"Did not successfully proxy server command"},"sessionId":"9c4c76e1bdc1d4de5a3449e9b11d8a9c"}
info: <-- POST /wd/hub/session/9c4c76e1bdc1d4de5a3449e9b11d8a9c/execute_async 500 60095.160 ms - 206
info: [debug] Chromedriver exited with code null
info: [debug] (killed by signal SIGTERM)
info: [debug] executing: "C:\myusername\Schulung\2014-05-Android-Grundlagen\adt-bundle-windows-x86_64-20140321\sdk\platform-tools\adb.exe" -s 0482067d5fXXXXX shell "am force-stop com.android.chrome"
info: [debug] Stopping logcat capture
info: [debug] Logcat terminated with code null, signal SIGTERM
info: [debug] Cleaning up appium session
info: [debug] We shut down because no new commands came in

setup/capabilities look okish. please help.

solved, not an appium issue. (protractor does not like $timeout)

read the full answer here: http://stackoverflow.com/questions/26299173/protractors-waitforangular-fails-on-angular-webapp-appium-chrome-on-real-dev