appium: Appium/Nodejs goes out of memory after a long time running

Hi,

We’re trying to run a lot of test scripts in a row against Android on Windows7. And in the middle of test run Nodejs says that process out of memory and test run breaks up.

I’m using:

• Nodejs v0.10.26
• Appium v0.18.0 (the latest v1.0.0 did not tested yet - need to update Xpath locators)

Here’s more detailed appium log:

execute HTTP/1.1" 200 89 "-" "-"
info: [BOOTSTRAP] [info] Swiping from [x=648.0, y=592.0] to [x=72.0, y=592.0] wi
th steps: 28
info: [BOOTSTRAP] [info] Returning result: {"value":true,"status":0}
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/elements
debug: Request received with params: {"using":"id","value":"com.lgi.orionandroid
:id/date_picker_button"}
info: Pushing command to appium work queue: ["find",{"strategy":"id","selector":
"com.lgi.orionandroid:id/date_picker_button","context":"","multiple":true}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"find","
params":{"strategy":"id","selector":"com.lgi.orionandroid:id/date_picker_button"
,"context":"","multiple":true}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: find
info: [BOOTSTRAP] [debug] Finding com.lgi.orionandroid:id/date_picker_button usi
ng ID with the contextId:
info: [BOOTSTRAP] [info] Element[] is null: (0)
info: [BOOTSTRAP] [info] Element[] is null: (1)
info: [BOOTSTRAP] [info] Returning result: {"value":[{"ELEMENT":"75"}],"status":
0}
info: Responding to client with success: {"status":0,"value":[{"ELEMENT":"75"}],
"sessionId":"7b723ca2-8b35-473e-95bb-1d574edaa558"}
POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/elements 200 709ms - 1
24b
debug: 127.0.0.1 - - "POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/
elements HTTP/1.1" 200 124 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/elements
debug: Request received with params: {"using":"id","value":"com.lgi.orionandroid
:id/dateFilter"}
info: Pushing command to appium work queue: ["find",{"strategy":"id","selector":
"com.lgi.orionandroid:id/dateFilter","context":"","multiple":true}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"find","
params":{"strategy":"id","selector":"com.lgi.orionandroid:id/dateFilter","contex
t":"","multiple":true}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: find
info: [BOOTSTRAP] [debug] Finding com.lgi.orionandroid:id/dateFilter using ID wi
th the contextId:
info: [BOOTSTRAP] [info] Returning result: {"value":[],"status":0}
info: Responding to client with success: {"status":0,"value":[],"sessionId":"7b7
23ca2-8b35-473e-95bb-1d574edaa558"}
POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/elements 200 693ms - 8
7b
debug: 127.0.0.1 - - "POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/
elements HTTP/1.1" 200 87 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/element/75/attribute/text
debug: Request received with params: {}
info: Pushing command to appium work queue: ["element:getAttribute",{"elementId"
:"75","attribute":"text"}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"element
:getAttribute","params":{"elementId":"75","attribute":"text"}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: getAttribute
info: [BOOTSTRAP] [info] Returning result: {"value":"TODAY","status":0}
info: Responding to client with success: {"status":0,"value":"TODAY","sessionId"
:"7b723ca2-8b35-473e-95bb-1d574edaa558"}
GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/element/75/attribute/te
xt 200 1154ms - 92b
debug: 127.0.0.1 - - "GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/e
lement/75/attribute/text HTTP/1.1" 200 92 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/elements
debug: Request received with params: {"using":"id","value":"com.lgi.orionandroid
:id/date_picker_button"}
info: Pushing command to appium work queue: ["find",{"strategy":"id","selector":
"com.lgi.orionandroid:id/date_picker_button","context":"","multiple":true}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"find","
params":{"strategy":"id","selector":"com.lgi.orionandroid:id/date_picker_button"
,"context":"","multiple":true}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: find
info: [BOOTSTRAP] [debug] Finding com.lgi.orionandroid:id/date_picker_button usi
ng ID with the contextId:
info: [BOOTSTRAP] [info] Element[] is null: (0)
info: [BOOTSTRAP] [info] Element[] is null: (1)
info: [BOOTSTRAP] [info] Returning result: {"value":[{"ELEMENT":"76"}],"status":
0}
info: Responding to client with success: {"status":0,"value":[{"ELEMENT":"76"}],
"sessionId":"7b723ca2-8b35-473e-95bb-1d574edaa558"}
POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/elements 200 1347ms -
124b
debug: 127.0.0.1 - - "POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/
elements HTTP/1.1" 200 124 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/elements
debug: Request received with params: {"using":"id","value":"com.lgi.orionandroid
:id/dateFilter"}
info: Pushing command to appium work queue: ["find",{"strategy":"id","selector":
"com.lgi.orionandroid:id/dateFilter","context":"","multiple":true}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"find","
params":{"strategy":"id","selector":"com.lgi.orionandroid:id/dateFilter","contex
t":"","multiple":true}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: find
info: [BOOTSTRAP] [debug] Finding com.lgi.orionandroid:id/dateFilter using ID wi
th the contextId:
info: Responding to client with success: {"status":0,"value":[],"sessionId":"7b7
23ca2-8b35-473e-95bb-1d574edaa558"}
POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/elements 200 57ms - 87
b
debug: 127.0.0.1 - - "POST /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/
elements HTTP/1.1" 200 87 "-" "-"
info: [BOOTSTRAP] [info] Returning result: {"value":[],"status":0}
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/element/76/attribute/text
debug: Request received with params: {}
info: Pushing command to appium work queue: ["element:getAttribute",{"elementId"
:"76","attribute":"text"}]
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"element
:getAttribute","params":{"elementId":"76","attribute":"text"}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: getAttribute
info: [BOOTSTRAP] [info] Returning result: {"value":"TODAY","status":0}
info: Responding to client with success: {"status":0,"value":"TODAY","sessionId"
:"7b723ca2-8b35-473e-95bb-1d574edaa558"}
GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/element/76/attribute/te
xt 200 1350ms - 92b
debug: 127.0.0.1 - - "GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/e
lement/76/attribute/text HTTP/1.1" 200 92 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558/screenshot
debug: Request received with params: {}
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "/system/bin/rm /data/local/tmp/screenshot.png; /system/bin/scree
ncap -p /data/local/tmp/screenshot.png "
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 pull /data/local/tmp/screenshot.png "C:\\Users\\SIARHE~1.MIN\\AppData\\
Local\\Temp\\appium11447-8484-mhwvr0.png"
info: Responding to client with success: {"status":0,"value":"iVBORw0KGgoAAAANSU
hEUgAAAtAAAAUACAYAAABuzmU9AAAABHNCSVQICAgIfAhkiAAAIABJREFUeJzsvXecVdW5///Zp01lKj
CUofcBpErRKAoWxE5iiyaaxEtyvfcmmmLU5Bo1McV8o0ksye/G+FKjRpGIiiBFMIB06QpDlz4zMEyvp+
zfH7iP+6xZbe9TZkae9+sF5+y1nvWsZ+29z9mf/cw6axsATBAEQRAEQRAEoYWnvQMgCIIgCIIgiM4ECW
iCIAiCIAiCcAAJaIIgCIIgCIJwAAlogiAIgiAIgnAACWiCIAiCIAiCcAAJaIIgCIIgCIJwAAlogiAIgi
A6JIZhRP91FjpTrIR7DNA60ARBEARBtDOW8DQMA5FIRGjn8Xhgmmeli/Xa0bBijDc+b1o6vGkZQj+GYS
Dc0oRwS3Nc/RDO8bV3AARBEARBnFvYs7SsGLZevV4vfL4vZEooFEI4HOaKa56/VGO/ARg/fjy2b9+OYD
DowMEXkwIMrweIRNB7+mz0uerriARb22S2TdOExx/A0fdfw9ElrwMeD8ywbd+Y4psQIn5IQBMEQRAEkR
IsEWgXuT6fD9nZ2ejRowfy8vKQmZmJnJwcpKenIz09PWrX3NyM5uZm1NbWorGxEdXV1SgrK0N9fT1CoZ
C0j1RhmibGjRuHPn36YMuWLQ4bfyF4zdDZ94bPD19GFpCRJWxm+PwwIxFAkrUnEg8JaIIgCIIgkophGD
FTGrKzs9G7d28UFxdjwIABKCgoiIplj0f98ywrC93c3IwzZ87g0KFDOHbsGI4fP476+vo2/SYbq5/hw4
djyJAhaGpqcjQX2vB4kNO9FzxeH0zThOHxINjagoycPODz/cbLQBuGgYycPGR37wV/IA1mJHJ2Ckw4hN
qKE2eFNZEUaA40QRAEQRBJgRWwvXv3RklJCYYMGYKuXbvCMAzXc5rZOdOmaeL06dPYt28fdu3ahePHjw
vjSCQejweRSAT9+vXDpEmT...","sessionId":"7b723ca2-8b35-473e-95bb-1d574edaa558"}
GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/screenshot 200 112444ms
 - 226.56kb
debug: 127.0.0.1 - - "GET /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558/s
creenshot HTTP/1.1" 200 231995 "-" "-"
debug: Appium request initiated at /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574
edaa558
debug: Request received with params: {}
info: Shutting down appium session...
info: [ADB] Pressing the HOME button
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "input keyevent 3"
info: Stopping logcat capture
debug: Logcat terminated with code null, signal SIGTERM
info: Sent shutdown command, waiting for UiAutomator to stop...
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"shutdown"}
info: [BOOTSTRAP] [info] Got command of type SHUTDOWN
info: [BOOTSTRAP] [info] Returning result: {"value":"OK, shutting down","status"
:0}
info: [BOOTSTRAP] [info] Closed client connection
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: current=1
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.boots
trap.Bootstrap
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=.
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: numtests=1
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: 0
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=
info: [UIAUTOMATOR STDOUT] Test results for WatcherResultPrinter=.
info: [UIAUTOMATOR STDOUT] Time: 1207.728
info: [UIAUTOMATOR STDOUT] OK (1 test)
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: -1
warn: UiAutomator did not shut down fast enough, calling it gone
info: Cleaning up android objects
info: Cleaning up appium session
info: Responding to client with success: {"status":0,"value":null,"sessionId":"7
b723ca2-8b35-473e-95bb-1d574edaa558"}
DELETE /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa558 200 10937ms - 89b
debug: 127.0.0.1 - - "DELETE /wd/hub/session/7b723ca2-8b35-473e-95bb-1d574edaa55
8 HTTP/1.1" 200 89 "-" "-"
debug: Appium request initiated at /wd/hub/session
debug: Request received with params: {"desiredCapabilities":{"newCommandTimeout"
:"120","app":"D:\\\\orion_android.apk","host-machine":{"username":null,"hostname
":"127.0.0.1","password
":null,"hCode":-139673956},"device-ready-timeout":"120","app-package":"com.lgi.o
rionandroid","launchTimeout":"120000","proxy-port":null,"device":"android","app-
activity":".ui.activity.SignInActivity","version":"4.3"}}
warn: Converting cap host-machine to string, since it was an object. This might
be a user error. Original value was: {"username":null,"hostname":"127.0.0.1",
"password":null,"hCode":-139673956}
info: Using local app from desired caps: D:\orion_android.apk
info: Creating new appium session 6a076242-e26b-4466-88c9-6c6390db1142
info: Starting android appium
debug: Using fast reset? true
info: Preparing device for session
info: Checking whether app is actually present
info: Checking whether adb is present
info: [ADB] Using adb from d:\android-sdk-windows\platform-tools\adb.exe
info: Trying to find a connected android device
info: [ADB] Getting connected devices...
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" devices
info: [ADB] 1 device(s) connected
info: Setting device id to 192.168.56.101:5555
info: [ADB] Waiting for device to be ready and to respond to shell commands (tim
eout = 120)
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 wait-for-device
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "echo 'ready'"
info: Starting logcat capture
info: Getting device API level
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "getprop ro.build.version.sdk"
info: Device is at API Level 18
debug: java -jar "D:\Mobile_CRS\APPIUM\Appium_v0.18.0\node_modules\appium\lib\de
vices\android\helpers\strings_from_apk.jar" "D:\orion_android.apk" "C:\Windows\T
emp\com.lgi.orionandroid"
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 push "C:\\Windows\\Temp\\com.lgi.orionandroid\\strings.json" /data/loca
l/tmp
info: Checking whether aapt is present
info: [ADB] Using aapt from d:\android-sdk-windows\build-tools\19.0.1\aapt.exe
debug: processFromManifest: "d:\android-sdk-windows\build-tools\19.0.1\aapt.exe"
 dump xmltree D:\orion_android.apk AndroidManifest.xml
debug: Set app process to: gi.orionandroid
debug: Not uninstalling app since server not started with --full-reset
debug: Checking app cert for D:\orion_android.apk: java -jar "D:\Mobile_CRS\APPI
UM\Appium_v0.18.0\node_modules\appium\lib\devices\android\helpers\verify.jar" "D
:\orion_android.apk"
debug: App already signed.
info: Zip-aligning D:\orion_android.apk
info: Checking whether zipalign is present
info: [ADB] Using zipalign from d:\android-sdk-windows\tools\zipalign.exe
debug: zipAlignApk: "d:\android-sdk-windows\tools\zipalign.exe" -f 4 "D:\orion_a
ndroid.apk" "C:\Users\SIARHE~1.MIN\AppData\Local\Temp\appium11447-8484-1k7bhx4.t
mp"
info: MD5 for app is ca0a4d5bb3b03b7cd00212492fa5ba14
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "ls /data/local/tmp/ca0a4d5bb3b03b7cd00212492fa5ba14.apk"
debug: Getting install status for com.lgi.orionandroid
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "pm list packages -3 com.lgi.orionandroid"
info: [ADB] App is installed
info: Running fast reset (stop and clear)
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "am force-stop com.lgi.orionandroid"
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "pm clear com.lgi.orionandroid"
info: [ADB] Forwarding system:4724 to device:4724
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 forward tcp:4724 tcp:4724
debug: Pushing appium bootstrap to device...
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 push "D:\\Mobile_CRS\\APPIUM\\Appium_v0.18.0\\node_modules\\appium\\bui
ld\\android_bootstrap\\AppiumBootstrap.jar" /data/local/tmp/
debug: Pushing unlock helper app to device...
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 install "D:\Mobile_CRS\APPIUM\Appium_v0.18.0\node_modules\appium\build\
unlock_apk\unlock_apk-debug.apk"
info: Attempting to kill all 'uiautomator' processes
info: Getting all processes with 'uiautomator'
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "ps 'uiautomator'"
info: No matching processes found
info: Running bootstrap
debug: spawning: d:\android-sdk-windows\platform-tools\adb.exe -s 192.168.56.101
:5555 shell uiautomator runtest AppiumBootstrap.jar -c io.appium.android.bootstr
ap.Bootstrap
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: current=1
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: id=UiAutomatorTestRunner
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: class=io.appium.android.boots
trap.Bootstrap
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: stream=
info: [UIAUTOMATOR STDOUT] io.appium.android.bootstrap.Bootstrap:
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: numtests=1
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS: test=testRunServer
info: [UIAUTOMATOR STDOUT] INSTRUMENTATION_STATUS_CODE: 1
info: [BOOTSTRAP] [info] Socket opened on port 4724
info: [BOOTSTRAP] [info] Appium Socket Server Ready
info: [BOOTSTRAP] [info] Loading json...
info: [BOOTSTRAP] [info] json loading complete.
info: [BOOTSTRAP] [info] Registered crash watchers.
debug: Waking up device if it's not alive
info: Pushing command to appium work queue: ["wake",{}]
info: [BOOTSTRAP] [info] Client connected
info: [BOOTSTRAP] [info] Got data from client: {"cmd":"action","action":"wake","
params":{}}
info: [BOOTSTRAP] [info] Got command of type ACTION
info: [BOOTSTRAP] [debug] Got command action: wake
info: [BOOTSTRAP] [info] Returning result: {"value":true,"status":0}
debug: executing: "d:\android-sdk-windows\platform-tools\adb.exe" -s 192.168.56.
101:5555 shell "dumpsys window"
FATAL ERROR: CALL_AND_RETRY_2 Allocation failed - process out of memory

Is there any cure on this ?