Appium + Protractor + Android Device error timeout

Question

I'm stuck at an error that I don't know exactly how to solve, the problems comes from here:

[debug] [MJSONWP] Calling AppiumDriver.timeouts() with args: ["script",11000,"bb157408-9234-4a81-a973-091bc4ccbe6d"]
[MJSONWP] Encountered internal error running command: Error: Invalid timeout 'script'

Why is sending as first parameter an "script"?

I'm new on e2e testing.

Thank in advance.

This is my config:

e2e-test.conf.js:

exports.config = {

    /*
    * normally protactor run tests on localhost:4444, but we want protactor to connect
    * appium which runs on localhost:4723
    */
    seleniumAddress: 'http://localhost:4723/wd/hub',
    specs: ['e2e-tests/*.test.js'],
    /* 
    * Some capabilities must be set to make sure appium can connect to your deice.
    * platformVersion: this is the version of Android
    * deviceName: your actual device name
    * browserName: leave this empty, we want protactor to use embeded webview
    * autoWebView: set this to true for hybrid applications
    * app: the location of the apk (must be absolute)
    */
    capabilities: {
        platformName: 'android',
        platformVersion: '5.1.1',
        deviceName: 'Nexus 4',
        browserName: '',
        autoWebView: true,
        app: '/Users/mikel/insurance/front/insurance/platforms/android/build/outputs/apk/android-debug.apk'
    },
        /* 
        * Default android localhost url
        */
        baseUrl: 'http://10.0.2.2:8000/',

        // configuring wd in onPrepare
  // wdBridge helps to bridge wd driver with other selenium clients
  // See https://github.com/sebv/wd-bridge/blob/master/README.md
  onPrepare: function () {
    var wd = require('wd'),
      protractor = require('protractor'),
      wdBridge = require('wd-bridge')(protractor, wd);
    wdBridge.initFromProtractor(exports.config);
  }
        
};

This is protractor output log:

(node:7447) DeprecationWarning: os.tmpDir() is deprecated. Use os.tmpdir() instead.
[17:28:30] I/launcher - Running 1 instances of WebDriver
[17:28:30] I/hosted - Using the selenium server at http://localhost:4723/wd/hub
[17:29:12] E/runner - Unable to start a WebDriver session.
[17:29:15] E/launcher - Error: WebDriverError: An unknown server-side error occurred while processing the command. Original error: Invalid timeout 'script'
    at Object.checkLegacyResponse (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/error.js:505:15)
    at parseHttpResponse (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/http.js:509:13)
    at doSend.then.response (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/http.js:440:13)
    at process._tickCallback (internal/process/next_tick.js:103:7)
From: Task: WebDriver.manage().timeouts().setScriptTimeout(11000)
    at WebDriver.schedule (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/webdriver.js:816:17)
    at Timeouts._scheduleCommand (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/webdriver.js:1500:25)
    at Timeouts.setScriptTimeout (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/webdriver.js:1483:17)
    at browser_.ready.browser_.ready.then.then (/usr/local/lib/node_modules/protractor/lib/runner.ts:281:49)
    at ManagedPromise.invokeCallback_ (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/promise.js:1366:14)
    at TaskQueue.execute_ (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/promise.js:2970:14)
    at TaskQueue.executeNext_ (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/promise.js:2953:27)
    at asyncRun (/usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/promise.js:2813:27)
    at /usr/local/lib/node_modules/protractor/node_modules/selenium-webdriver/lib/promise.js:676:7
    at process._tickCallback (internal/process/next_tick.js:103:7)
[17:29:15] E/launcher - Process exited with error code 100

This is Appium output log:

[debug] [UiAutomator] Starting UIAutomator
[debug] [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","04f4019957958336","shell","uiautomator","runtest","AppiumBootstrap.jar","-c","io.appium.android.bootstrap.Bootstrap","-e","pkg","com.ionicframework.insurance437011","-e","disableAndroidWatchers",false,"-e","acceptSslCerts",false]
[debug] [UiAutomator] Moving to state 'online'
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] json loading complete.
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Registered crash watchers.
[AndroidBootstrap] Android bootstrap socket is now connected
[debug] [ADB] Device API level: 22
[debug] [ADB] Getting connected devices...
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Client connected
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","am","start","-W","-n","com.ionicframework.insurance437011/com.ionicframework.insurance437011.MainActivity","-S","-a","android.intent.action.MAIN","-c","android.intent.category.LAUNCHER","-f","0x10200000"]
[debug] [ADB] Waiting for pkg: 'com.ionicframework.insurance437011' and activity: 'com.ionicframework.insurance437011.MainActivity' to be focused
[debug] [ADB] Possible activities, to be checked: com.ionicframework.insurance437011.MainActivity, .MainActivity, .com.ionicframework.insurance437011.MainActivity
[debug] [ADB] Getting focused package and activity
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","dumpsys","window","windows"]
[debug] [ADB] Found package: 'com.ionicframework.insurance437011' and activity: '.MainActivity'
[Appium] New AndroidDriver session created successfully, session bb157408-9234-4a81-a973-091bc4ccbe6d added to master session list
[debug] [MJSONWP] Responding to client with driver.createSession() result: {"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"platformName":"android","platformVersion":"5.1.1","deviceName":"Nexus 4","browserName":"","autoWebView":true,"app":"/Users/mikel/insurance/front/insurance/platforms/android/build/outputs/apk/android-debug.apk","count":1},"platformName":"android","platformVersion":"5.1.1","deviceName":"04f4019957958336","browserName":"","autoWebView":true,"app":"/Users/mikel/insurance/front/insurance/platforms/android/build/outputs/apk/android-debug.apk","count":1,"deviceUDID":"04f4019957958336","appPackage":"com.ionicframework.insurance437011","appWaitPackage":"com.ionicframework.insurance437011","appActivity":"com.ionicframework.insurance437011.MainActivity","appWaitActivity":"com.ionicframework.insurance437011.MainActivity"}
[HTTP] <-- POST /wd/hub/session 200 220004 ms - 998 
[HTTP] --> POST /wd/hub/session/bb157408-9234-4a81-a973-091bc4ccbe6d/timeouts {"type":"script","ms":11000}
[debug] [MJSONWP] Calling AppiumDriver.timeouts() with args: ["script",11000,"bb157408-9234-4a81-a973-091bc4ccbe6d"]
[MJSONWP] Encountered internal error running command: Error: Invalid timeout 'script'
    at AndroidDriver.callee$0$0$ (../../../../lib/basedriver/commands/timeout.js:23:13)
    at tryCatch (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:67:40)
    at GeneratorFunctionPrototype.invoke [as _invoke] (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:315:22)
    at GeneratorFunctionPrototype.prototype.(anonymous function) [as next] (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:100:21)
    at invoke (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:136:37)
    at enqueueResult (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:185:17)
    at F (/usr/local/lib/node_modules/appium/node_modules/core-js/library/modules/$.export.js:30:36)
    at AsyncIterator.enqueue (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:184:12)
    at AsyncIterator.prototype.(anonymous function) [as next] (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:100:21)
    at Object.runtime.async (/usr/local/lib/node_modules/appium/node_modules/babel-runtime/regenerator/runtime.js:209:12)
    at AndroidDriver.callee$0$0 [as timeouts] (../../../../lib/basedriver/commands/timeout.js:14:9)
    at ../../../lib/basedriver/driver.js:173:24
    at tryCatcher (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/util.js:26:23)
    at Promise._settlePromiseFromHandler (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/promise.js:510:31)
    at Promise._settlePromiseAt (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/promise.js:584:18)
    at Promise._settlePromiseAtPostResolution (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/promise.js:248:10)
    at Async._drainQueue (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/async.js:128:12)
    at Async._drainQueues (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/async.js:133:10)
    at Immediate.Async.drainQueues (/usr/local/lib/node_modules/appium/node_modules/bluebird/js/main/async.js:15:14)
    at runCallback (timers.js:651:20)
    at tryOnImmediate (timers.js:624:5)
    at processImmediate [as _immediateCallback] (timers.js:596:5)
[HTTP] <-- POST /wd/hub/session/bb157408-9234-4a81-a973-091bc4ccbe6d/timeouts 500 9 ms - 195 
[HTTP] --> DELETE /wd/hub/session/bb157408-9234-4a81-a973-091bc4ccbe6d {}
[debug] [MJSONWP] Calling AppiumDriver.deleteSession() with args: ["bb157408-9234-4a81-a973-091bc4ccbe6d"]
[debug] [AndroidDriver] Shutting down Android driver
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","am","force-stop","com.ionicframework.insurance437011"]
[debug] [ADB] Pressing the HOME button
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","input","keyevent",3]
[debug] [AndroidBootstrap] Sending command to android: {"cmd":"shutdown"}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"shutdown"}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type SHUTDOWN
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"status":0,"value":"OK, shutting down"}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Closed client connection
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: numtests=1
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream=.
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.bootstrap.Bootstrap
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: current=1
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: 0
[debug] [AndroidBootstrap] Received command result from bootstrap
[debug] [UiAutomator] Shutting down UiAutomator
[debug] [UiAutomator] Moving to state 'stopping'
[debug] [UiAutomator] UiAutomator shut down normally
[debug] [UiAutomator] Moving to state 'stopped'
[debug] [ADB] Attempting to kill all uiautomator processes
[debug] [ADB] Getting all processes with uiautomator
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","ps"]
[ADB] No uiautomator process found to kill, continuing...
[debug] [UiAutomator] Moving to state 'stopped'
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/Users/mikel/Library/Android/sdk/platform-tools/adb' with args: ["-P",5037,"-s","04f4019957958336","shell","am","force-stop","io.appium.unlock"]
[debug] [Logcat] Stopping logcat capture
[debug] [AndroidDriver] Not cleaning generated files. Add `clearSystemFiles` capability if wanted.
[Appium] Removing session bb157408-9234-4a81-a973-091bc4ccbe6d from our master session list
[debug] [MJSONWP] Received response: null
[debug] [MJSONWP] But deleting session, so not returning
[debug] [MJSONWP] Responding to client with driver.deleteSession() result: null
[HTTP] <-- DELETE /wd/hub/session/bb157408-9234-4a81-a973-091bc4ccbe6d 200 3740 ms - 76 

Answer 1

I had the exact same problem and solved it by using both the autoWebview and autoWebviewTimeout capabilities.

My capabilities currently look like this:

capabilities: {
    browserName: '',
    'appium-version': '1.6',
    platformName: 'Android',
    platformVersion: '7.0',
    deviceName: '66c4518f',
    app: './platforms/android/build/outputs/apk/android-debug.apk',
    autoWebview: true,
    autoWebviewTimeout: 20000,
    newCommandTimeout: 300000
}

Hope this solves your problem. I know I spent a loooot of time finding this one...

More information as to why you should use this capability can be found here.