Appium bug gist

appium log

[HTTP] --> POST /wd/hub/session {"desiredCapabilities":{"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"}}
[debug] [MJSONWP] Calling AppiumDriver.createSession() with args: [{"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"},null,null,null,null,null,null]
[Appium] Creating new AndroidDriver session
[Appium] Capabilities:
[Appium]   browserName: ''
[Appium]   appium-version: '1.3'
[Appium]   platformName: 'Android'
[Appium]   platformVersion: '6.0'
[Appium]   deviceName: 'Android Emulator'
[Appium]   app: 'android/app/build/outputs/apk/app-release.apk'
[debug] [AndroidDriver] AndroidDriver version: 1.10.38
[BaseDriver] The following capabilities were provided, but are not recognized by appium: appium-version.
[BaseDriver] Session created with session id: 952a9f98-cece-4dd3-8512-8f6401460e8a
[debug] [AndroidDriver] Getting Java version
[AndroidDriver] Java version is: 1.8.0_111
[ADB] Checking whether adb is present
[ADB] Using adb from /home/adam/Android/Sdk/platform-tools/adb
[AndroidDriver] Retrieving device list
[debug] [ADB] Trying to find a connected android device
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[AndroidDriver] Looking for a device with Android '6.0'
[debug] [ADB] Setting device id to emulator-5554
[ADB] Getting device platform version
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","getprop","ro.build.version.release"]
[AndroidDriver] Using device: emulator-5554
[ADB] Checking whether adb is present
[ADB] Using adb from /home/adam/Android/Sdk/platform-tools/adb
[debug] [ADB] Setting device id to emulator-5554
[BaseDriver] Using local app 'android/app/build/outputs/apk/app-release.apk'
[debug] [AndroidDriver] Checking whether app is actually present
[AndroidDriver] Starting Android session
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","wait-for-device"]
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","echo","ping"]
[debug] [Logcat] Starting logcat capture
[debug] [AndroidDriver] Pushing settings apk to device...
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","install","/home/adam/apps/dual-n-back/node_modules/io.appium.settings/bin/settings_apk-debug.apk"]
[debug] [AndroidDriver] Pushing unlock helper app to device...
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","install","/home/adam/apps/dual-n-back/node_modules/appium-unlock/bin/unlock_apk-debug.apk"]
[ADB] Getting device platform version
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","getprop","ro.build.version.release"]
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","dumpsys","window"]
[AndroidDriver] Screen already unlocked, doing nothing
[debug] [AndroidDriver] Parsing package and activity from app manifest
[ADB] Checking whether aapt is present
[ADB] Using aapt from /home/adam/Android/Sdk/build-tools/24.0.2/aapt
[ADB] Extracting package and launch activity from manifest
[debug] [ADB] badging package: com.memoryNback
[debug] [ADB] badging act: com.memoryNback.MainActivity
[debug] [AndroidDriver] Parsed package and activity are: com.memoryNback/com.memoryNback.MainActivity
[AndroidDriver] Remote apk path is /data/local/tmp/0e45a3c12882e3ee24039595941aa5f0.apk
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","ls","/data/local/tmp/0e45a3c12882e3ee24039595941aa5f0.apk"]
[debug] [AndroidDriver] Checking if app is installed
[debug] [ADB] Getting install status for com.memoryNback
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","getprop","ro.build.version.sdk"]
[debug] [ADB] Device API level: 23
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","pm","list","packages","-3","com.memoryNback"]
[debug] [ADB] App is  installed
[AndroidDriver] Apk is already on remote and installed, resetting
[debug] [AndroidDriver] Running fast reset (stop and clear)
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","am","force-stop","com.memoryNback"]
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","pm","clear","com.memoryNback"]
[debug] [AndroidDriver] Extracting strings from apk android/app/build/outputs/apk/app-release.apk null /tmp/com.memoryNback
[debug] [ADB] Extracting strings for language: default
[debug] [ADB] Device API level: 23
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","getprop","persist.sys.locale"]
[debug] [ADB] Current device property 'persist.sys.locale': 
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","getprop","ro.product.locale"]
[debug] [ADB] Current device property 'ro.product.locale': en-US
[debug] [ADB] No strings.xml for language 'en', getting default strings.xml
[debug] [ADB] Reading strings from converted strings.json
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","push","/tmp/com.memoryNback/strings.json","/data/local/tmp"]
[debug] [AndroidBootstrap] Watching for bootstrap disconnect
[debug] [ADB] Forwarding system: 4724 to device: 4724
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","forward","tcp:4724","tcp:4724"]
[debug] [UiAutomator] Starting UiAutomator
[debug] [UiAutomator] Moving to state 'starting'
[debug] [UiAutomator] Parsing uiautomator jar
[debug] [UiAutomator] Found jar name: 'AppiumBootstrap.jar'
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","push","/home/adam/apps/dual-n-back/node_modules/appium-android-bootstrap/bootstrap/bin/AppiumBootstrap.jar","/data/local/tmp/"]
[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 '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","ps"]
[ADB] No uiautomator process found to kill, continuing...
[debug] [UiAutomator] Starting UIAutomator
[debug] [ADB] Creating ADB subprocess with args: ["-P",5037,"-s","emulator-5554","shell","uiautomator","runtest","AppiumBootstrap.jar","-c","io.appium.android.bootstrap.Bootstrap","-e","pkg","com.memoryNback","-e","disableAndroidWatchers",false,"-e","acceptSslCerts",false]
[debug] [UiAutomator] Moving to state 'online'
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Loading json...
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] json loading complete.
[AndroidBootstrap] Android bootstrap socket is now connected
[debug] [ADB] Device API level: 23
[debug] [ADB] Getting connected devices...
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Registered crash watchers.
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Client connected
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","am","start","-W","-n","com.memoryNback/com.memoryNback.MainActivity","-S","-a","android.intent.action.MAIN","-c","android.intent.category.LAUNCHER","-f","0x10200000"]
[debug] [ADB] Waiting for pkg: 'com.memoryNback' and activity: 'com.memoryNback.MainActivity' to be focused
[debug] [ADB] Possible activities, to be checked: com.memoryNback.MainActivity, .MainActivity, .com.memoryNback.MainActivity
[debug] [ADB] Getting focused package and activity
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","dumpsys","window","windows"]
[debug] [ADB] Found package: 'com.memoryNback' and activity: '.MainActivity'
[Appium] New AndroidDriver session created successfully, session 952a9f98-cece-4dd3-8512-8f6401460e8a 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":{"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"},"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"emulator-5554","app":"android/app/build/outputs/apk/app-release.apk","deviceUDID":"emulator-5554","appPackage":"com.memoryNback","appWaitPackage":"com.memoryNback","appActivity":"com.memoryNback.MainActivity","appWaitActivity":"com.memoryNback.MainActivity"}
[HTTP] <-- POST /wd/hub/session 200 4575 ms - 815 
[HTTP] --> POST /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a/timeouts/implicit_wait {"ms":3000}
[debug] [MJSONWP] Calling AppiumDriver.implicitWait() with args: [3000,"952a9f98-cece-4dd3-8512-8f6401460e8a"]
[debug] [BaseDriver] Set implicit wait to 3000ms
[debug] [MJSONWP] Responding to client with driver.implicitWait() result: null
[HTTP] <-- POST /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a/timeouts/implicit_wait 200 1 ms - 76 
[HTTP] --> POST /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a/element {"using":"accessibility id","value":"Graphics"}
[debug] [MJSONWP] Calling AppiumDriver.findElement() with args: ["accessibility id","Graphics","952a9f98-cece-4dd3-8512-8f6401460e8a"]
[debug] [BaseDriver] Valid locator strategies for this request: xpath, id, class name, accessibility id, -android uiautomator
[debug] [BaseDriver] Valid locator strategies for this request: xpath, id, class name, accessibility id, -android uiautomator
[debug] [BaseDriver] Waiting up to 3000 ms for condition
[debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"find","params":{"strategy":"accessibility id","selector":"Graphics","context":"","multiple":false}}
[HTTP] --> DELETE /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a {}
[debug] [MJSONWP] Calling AppiumDriver.deleteSession() with args: ["952a9f98-cece-4dd3-8512-8f6401460e8a"]
[debug] [AndroidDriver] Shutting down Android driver
[debug] [ADB] Getting connected devices...
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"find","params":{"strategy":"accessibility id","selector":"Graphics","context":"","multiple":false}}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: find
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding 'Graphics' using 'ACCESSIBILITY_ID' with the contextId: '' multiple: false
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[DESCRIPTION=Graphics, INSTANCE=0]
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","am","force-stop","com.memoryNback"]
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Failed to locate element. Clearing Accessibility cache and retrying.
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding 'Graphics' using 'ACCESSIBILITY_ID' with the contextId: '' multiple: false
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[DESCRIPTION=Graphics, INSTANCE=0]
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"status":7,"value":"No element found"}
[debug] [AndroidBootstrap] Received command result from bootstrap
[debug] [BaseDriver] Waited for 154 ms so far
[debug] [ADB] Pressing the HOME button
[debug] [ADB] Getting connected devices...
[debug] [ADB] 1 device(s) connected
[debug] [ADB] Running '/home/adam/Android/Sdk/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","input","keyevent",3]
[debug] [AndroidBootstrap] Sending command to android: {"cmd":"action","action":"find","params":{"strategy":"accessibility id","selector":"Graphics","context":"","multiple":false}}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got data from client: {"cmd":"action","action":"find","params":{"strategy":"accessibility id","selector":"Graphics","context":"","multiple":false}}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command of type ACTION
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Got command action: find
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding 'Graphics' using 'ACCESSIBILITY_ID' with the contextId: '' multiple: false
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[DESCRIPTION=Graphics, INSTANCE=0]
[debug] [AndroidBootstrap] Sending command to android: {"cmd":"shutdown"}
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Failed to locate element. Clearing Accessibility cache and retrying.
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Finding 'Graphics' using 'ACCESSIBILITY_ID' with the contextId: '' multiple: false
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Using: UiSelector[DESCRIPTION=Graphics, INSTANCE=0]
[AndroidBootstrap] [BOOTSTRAP LOG] [debug] Returning result: {"status":7,"value":"No element found"}
[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] [UIAUTO STDOUT] INSTRUMENTATION_STATUS: stream=
[debug] [AndroidBootstrap] [UIAUTO STDOUT] Test results for WatcherResultPrinter=.
[debug] [AndroidBootstrap] [UIAUTO STDOUT] Time: 7.65
[debug] [AndroidBootstrap] [UIAUTO STDOUT] OK (1 test)
[debug] [AndroidBootstrap] [UIAUTO STDOUT] INSTRUMENTATION_STATUS_CODE: -1
[debug] [AndroidBootstrap] Received command result from bootstrap
[debug] [AndroidBootstrap] Stream still not complete, waiting
[debug] [AndroidBootstrap] Received command result from bootstrap
[debug] [AndroidBootstrap] Stream still not complete, waiting
[UiAutomator] UiAutomator exited unexpectedly with code 0, signal null
[debug] [UiAutomator] Moving to state 'stopped'
[HTTP] <-- POST /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a/element - - ms - - 
[HTTP] <-- DELETE /wd/hub/session/952a9f98-cece-4dd3-8512-8f6401460e8a - - ms - - 

output of mocha path_to_test.js

➜  dual-n-back git:(native-e2e) ✗ npm run e2e:android

> memoryNBack@1.0.3 e2e:android /home/adam/apps/dual-n-back
> mocha test/e2e-native/home.spec.js



  android simple
 > CALL init({"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"}) 
 > POST /session {"desiredCapabilities":{"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"}}

Driving the web on session: 952a9f98-cece-4dd3-8512-8f6401460e8a

 > RESPONSE init({"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"}) "952a9f98-cece-4dd3-8512-8f6401460e8a",{"platform":"LINUX","webStorageEnabled":false,"takesScreenshot":true,"javascriptEnabled":true,"databaseEnabled":false,"networkConnectionEnabled":true,"locationContextEnabled":false,"warnings":{},"desired":{"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"Android Emulator","app":"android/app/build/outputs/apk/app-release.apk"},"browserName":"","appium-version":"1.3","platformName":"Android","platformVersion":"6.0","deviceName":"emulator-5554","app":"android/app/build/outputs/apk/app-release.apk","deviceUDID":"emulator-5554","appPackage":"com.memoryNback","appWaitPackage":"com.memoryNback","appActivity":"com.memoryNback.MainActivity","appWaitActivity":"com.memoryNback.MainActivity"}
 > CALL setImplicitWaitTimeout(3000) 
 > POST /session/:sessionID/timeouts/implicit_wait {"ms":3000}
 > RESPONSE setImplicitWaitTimeout(3000) 
 > CALL elementByAccessibilityId("Graphics") 
 > POST /session/:sessionID/element {"using":"accessibility id","value":"Graphics"}
    ✓ should find an element (65ms)
 > CALL quit() 
 > DELETE /session/:sessionID 
    1) "after all" hook


  1 passing (5m)
  1 failing

  1) android simple "after all" hook:
     Error: timeout of 300000ms exceeded. Ensure the done() callback is being called in this test.
  




npm ERR! Linux 4.4.0-53-generic
npm ERR! argv "/usr/bin/nodejs" "/usr/bin/npm" "run" "e2e:android"
npm ERR! node v6.9.1
npm ERR! npm  v3.10.8
npm ERR! code ELIFECYCLE
npm ERR! memoryNBack@1.0.3 e2e:android: `mocha test/e2e-native/home.spec.js`
npm ERR! Exit status 1
npm ERR! 
npm ERR! Failed at the memoryNBack@1.0.3 e2e:android script 'mocha test/e2e-native/home.spec.js'.
npm ERR! Make sure you have the latest version of node.js and npm installed.
npm ERR! If you do, this is most likely a problem with the memoryNBack package,
npm ERR! not with npm itself.
npm ERR! Tell the author that this fails on your system:
npm ERR!     mocha test/e2e-native/home.spec.js
npm ERR! You can get information on how to open an issue for this project with:
npm ERR!     npm bugs memoryNBack
npm ERR! Or if that isn't available, you can get their info via:
npm ERR!     npm owner ls memoryNBack
npm ERR! There is likely additional logging output above.

npm ERR! Please include the following file with any support request:
npm ERR!     /home/adam/apps/dual-n-back/npm-debug.log
➜