Node out of memory when Appium tries to install large .apk

[samueljmurray]

I'm trying to run an Appium test script but Appium is failing with this error:

FATAL ERROR: CALL_AND_RETRY_0 Allocation failed - process out of memory

after executing this command:

debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/"

The .apk file I'm using is 99.8MB (it is a PhoneGap app that contains a lot of media content). I'd guess the Appium process is loading the whole file into memory - is there a way around this, or a memory limit that can be increased?

[jlipps]

What's the whole log? I want to make sure it's a node error and not a device error.

[samueljmurray]

Hi Jonathan, thanks for the reply. Here's a copy of the log from starting Appium to crash. Underneath it I've also pasted a copy of the log running Appium with the --trace-gc node flag set, which may help us find the problem.

debug: Appium request initiated at /wd/hub/session debug: Request received with params: {"desiredCapabilities":{"device":"selendroid","app":"/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk","app-package":"com.example.MyLargeApp.staging_188","app-activity":".MyLargeApp","app-wait-activity":"MyLargeApp"}} info: Using local app from desiredCaps: /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk info: Creating new appium session 155adb53-a40b-4977-9bb3-258e355da14c info: Starting selendroid server info: Checking whether selendroid is built yet info: Selendroid server exists! info: Preparing device for session info: Checking whether app is actually present info: Checking whether adb is present info: [ADB] Using adb from /Users/SamM/ADT/sdk/platform-tools/adb info: Trying to find a connected android device info: [ADB] Getting connected devices... debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" devices info: [ADB] 1 device(s) connected info: Setting device id to emulator-5554 info: [ADB] Waiting for device to be ready and to respond to shell commands (timeout = 5) debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 wait-for-device debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "echo 'ready'" info: Starting logcat capture info: Rebuilt selendroid apk does not exist, uninstalling any instances of it on device to make way for new one info: Uninstalling com.example.MyLargeApp.staging_188.selendroid debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 uninstall com.example.MyLargeApp.staging_188.selendroid debug: App was uninstalled info: Rebuilt selendroid server does not exist, inserting modified manifest info: Inserting selendroid manifest info: Checking whether aapt is present info: [ADB] Using aapt from /Users/SamM/ADT/sdk/platform-tools/aapt info: Compiling manifest /tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml debug: "/Users/SamM/ADT/sdk/platform-tools/aapt" package -M "/tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml" --rename-manifest-package "com.example.MyLargeApp.staging_188.selendroid" --rename-instrumentation-target-package "com.example.MyLargeApp.staging_188" -I "/Users/SamM/ADT/sdk/platforms/android-17/android.jar" -F "/tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml.apk" -f debug: Compiled manifest info: Inserting manifest, src: /usr/local/share/npm/lib/node_modules/appium/build/selendroid/selendroid.apk, dst: /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Extracting manifest info: Unzipping /tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml.apk info: Testing zip archive: /tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml.apk info: Zip archive tested clean info: Unzip successful debug: Writing tmp apk. /usr/local/share/npm/lib/node_modules/appium/build/selendroid/selendroid.apk to /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Testing new tmp apk. info: Testing zip archive: /tmp/selendroid.com.example.MyLargeApp.staging_188.apk info: Zip archive tested clean debug: Moving manifest with: zip -j -m "/tmp/selendroid.com.example.MyLargeApp.staging_188.apk" "/tmp/com.example.MyLargeApp.staging_188/AndroidManifest.xml" debug: Inserted manifest. info: Checking signed status of /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Checking app cert for /tmp/selendroid.com.example.MyLargeApp.staging_188.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/tmp/selendroid.com.example.MyLargeApp.staging_188.apk" info: Checking signed status of /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App not signed with debug cert. debug: Resigning apks with: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/sign.jar" "/tmp/selendroid.com.example.MyLargeApp.staging_188.apk" --override debug: App not signed with debug cert. debug: Resigning apks with: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/sign.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" --override debug: Getting install status for com.example.MyLargeApp.staging_188.selendroid debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188.selendroid" info: [ADB] App is not installed info: Rebuilt selendroid is not installed, installing it debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 install -r /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Getting install status for com.example.MyLargeApp.staging_188 debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188" info: [ADB] App is not installed debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App already signed. debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/" FATAL ERROR: CALL_AND_RETRY_0 Allocation failed - process out of memory

---

debug: Appium request initiated at /wd/hub/session debug: Request received with params: {"desiredCapabilities":{"device":"selendroid","app":"/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk","app-package":"com.example.MyLargeApp.staging_188","app-activity":".MyLargeApp","app-wait-activity":"MyLargeApp"}} info: Using local app from desiredCaps: /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk info: Creating new appium session bf948d51-8956-4f87-a664-e92b0b3a3ab0 info: Starting selendroid server info: Checking whether selendroid is built yet info: Selendroid server exists! info: Preparing device for session info: Checking whether app is actually present info: Checking whether adb is present info: [ADB] Using adb from /Users/SamM/ADT/sdk/platform-tools/adb info: Trying to find a connected android device info: [ADB] Getting connected devices... debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" devices info: [ADB] 1 device(s) connected info: Setting device id to emulator-5554 info: [ADB] Waiting for device to be ready and to respond to shell commands (timeout = 5) debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 wait-for-device debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "echo 'ready'" info: Starting logcat capture info: Rebuilt selendroid apk exists, doing nothing info: Rebuilt selendroid server already exists, no need to rebuild it with a new manifest info: Checking signed status of /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Checking app cert for /tmp/selendroid.com.example.MyLargeApp.staging_188.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/tmp/selendroid.com.example.MyLargeApp.staging_188.apk" info: Checking signed status of /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App already signed. debug: App already signed. debug: Getting install status for com.example.MyLargeApp.staging_188.selendroid debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188.selendroid" info: [ADB] App is not installed info: Rebuilt selendroid is not installed, installing it debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 install -r /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Getting install status for com.example.MyLargeApp.staging_188 debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188" info: [ADB] App is not installed debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App already signed. debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/" FATAL ERROR: CALL_AND_RETRY_0 Allocation failed - process out of memory arnold:~ SamM$ node --trace-gc /usr/local/share/npm/bin/Appium [743] 50 ms: Scavenge 2.6 (38.0) -> 2.2 (38.0) MB, 1 ms [allocation failure]. [743] 62 ms: Scavenge 3.2 (38.0) -> 2.7 (38.0) MB, 0 ms [allocation failure]. [743] 71 ms: Scavenge 3.5 (38.0) -> 3.1 (38.0) MB, 0 ms [allocation failure]. [743] 97 ms: Scavenge 5.2 (38.0) -> 4.1 (39.0) MB, 1 ms [allocation failure]. [743] 119 ms: Scavenge 5.9 (39.0) -> 4.8 (40.0) MB, 0 ms [allocation failure]. [743] 147 ms: Scavenge 6.8 (41.0) -> 5.7 (41.0) MB, 1 ms [Runtime::PerformGC]. [743] 196 ms: Mark-sweep 9.5 (41.0) -> 5.1 (41.0) MB, 7 ms [allocation failure] [promotion limit reached]. [743] 247 ms: Scavenge 9.6 (42.0) -> 6.8 (42.0) MB, 1 ms [Runtime::PerformGC]. [743] 280 ms: Scavenge 10.1 (42.0) -> 7.9 (43.0) MB, 2 ms [allocation failure]. [743] 330 ms: Scavenge 11.5 (44.0) -> 9.4 (45.0) MB, 2 ms [allocation failure]. [743] 413 ms: Mark-sweep 16.0 (47.0) -> 9.1 (47.0) MB, 6 ms (+ 7 ms in 61 steps since start of marking, biggest step 0.236084 ms) [StackGuard GC request] [GC in old space requested]. info: Welcome to Appium v0.12.0 (REV a9d21807874190ae6d19f8251375cfe4da7b2ae5) info: Appium REST http interface listener started on 0.0.0.0:4723 info - socket.io started [743] 525 ms: Scavenge 18.6 (48.0) -> 13.1 (48.0) MB, 2 ms [Runtime::PerformGC]. debug: Appium request initiated at /wd/hub/session debug: Request received with params: {"desiredCapabilities":{"device":"selendroid","app":"/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk","app-package":"com.example.MyLargeApp.staging_188","app-activity":".MyLargeApp","app-wait-activity":"MyLargeApp"}} info: Using local app from desiredCaps: /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk info: Creating new appium session 5ca23a73-e657-4d9d-8a38-89c699a6a5c9 info: Starting selendroid server info: Checking whether selendroid is built yet info: Selendroid server exists! info: Preparing device for session info: Checking whether app is actually present info: Checking whether adb is present info: [ADB] Using adb from /Users/SamM/ADT/sdk/platform-tools/adb info: Trying to find a connected android device info: [ADB] Getting connected devices... debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" devices info: [ADB] 1 device(s) connected info: Setting device id to emulator-5554 info: [ADB] Waiting for device to be ready and to respond to shell commands (timeout = 5) debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 wait-for-device debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "echo 'ready'" info: Starting logcat capture info: Rebuilt selendroid apk exists, doing nothing info: Rebuilt selendroid server already exists, no need to rebuild it with a new manifest info: Checking signed status of /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Checking app cert for /tmp/selendroid.com.example.MyLargeApp.staging_188.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/tmp/selendroid.com.example.MyLargeApp.staging_188.apk" info: Checking signed status of /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App already signed. debug: App already signed. debug: Getting install status for com.example.MyLargeApp.staging_188.selendroid debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188.selendroid" info: [ADB] App is not installed info: Rebuilt selendroid is not installed, installing it debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 install -r /tmp/selendroid.com.example.MyLargeApp.staging_188.apk debug: Getting install status for com.example.MyLargeApp.staging_188 debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "pm list packages -3 com.example.MyLargeApp.staging_188" info: [ADB] App is not installed debug: Checking app cert for /Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk: java -jar "/usr/local/share/npm/lib/node_modules/appium/lib/devices/android/helpers/verify.jar" "/Users/SamM/apache2_public/MyLargeApp/MyLargeApp.apk" debug: App already signed. debug: executing: "/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/" [743] 20212 ms: Mark-sweep 19.0 (49.0) -> 13.6 (51.0) MB, 23 ms [allocation failure] [GC in old space requested]. [743] 20288 ms: Mark-sweep 32.9 (70.4) -> 19.8 (57.4) MB, 26 ms [allocation failure] [GC in old space requested]. [743] 20372 ms: Mark-sweep 47.6 (85.2) -> 28.7 (66.7) MB, 18 ms [allocation failure] [GC in old space requested]. [743] 20542 ms: Mark-sweep 91.1 (129.1) -> 49.5 (87.5) MB, 28 ms [allocation failure] [GC in old space requested]. [743] 20697 ms: Mark-sweep 105.6 (143.7) -> 67.5 (106.2) MB, 28 ms [allocation failure] [GC in old space requested]. [743] 20931 ms: Mark-sweep 151.8 (190.5) -> 94.3 (133.3) MB, 35 ms [allocation failure] [GC in old space requested]. [743] 21278 ms: Mark-sweep 220.7 (259.7) -> 136.4 (174.4) MB, 54 ms [allocation failure] [GC in old space requested]. [743] 21774 ms: Mark-sweep 326.0 (364.1) -> 199.6 (237.6) MB, 68 ms [allocation failure] [GC in old space requested]. [743] 22513 ms: Mark-sweep 484.0 (522.1) -> 294.4 (332.4) MB, 99 ms [allocation failure] [GC in old space requested]. [743] 23618 ms: Mark-sweep 721.0 (759.1) -> 436.6 (474.6) MB, 145 ms [allocation failure] [GC in old space requested]. FATAL ERROR: CALL_AND_RETRY_0 Allocation failed - process out of memory

[jlipps]

what happens if you run

"/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/"

directly on your machine? does it work as expected? I'm baffled that running exec would cause Node to go out of memory. What version of Node are you on?

[samueljmurray]

"/Users/SamM/ADT/sdk/platform-tools/adb" -s emulator-5554 shell "mkdir -p /data/local/tmp/"

...runs without any problems and the folder is created.

I'm running node v0.10.22

Looking at the garbage collection trace that appears just before the error occurs, the last 2 entries show that the Appium process had 484MB of memory before GC ran, then 721MB before GC ran for the final time. The sequence suggests that after the last GC ran, Appium may have tried to take around 1GB of memory.

This article says that node has a memory limit of 1GB for a process on 64-bit systems: https://github.com/joyent/node/wiki/FAQ#what-is-the-memory-limit-on-a-node-process

I've tried setting --max-old-space-size=1500 when running Appium but I get the same GC trace (so it seems not to have any effect).

These discussions also suggest that v8 itself has a limit of 1GB on 64-bit (although one of them is +3 years old): https://groups.google.com/forum/#!topic/v8-users/c1-h945Bmns https://groups.google.com/forum/#!topic/nodejs/T8B58GTka5k

Does Appium copy the apk into memory when copying it to the device? If so, is it possible that doing this would require Appium to try to utilise +1GB of memory for a 100MB apk?

[jlipps]

No, appium doesn't copy anything into memory AFAIK. It is just running subprocesses. I think something else weird is going on. But you can get smaller apks to run fine?

[samueljmurray]

Yes, I've only tried one other apk which was 1.9MB and that ran fine.

Looking at the source code, it seems that Appium does read the whole apk into memory at line 170 in lib/devices/android/android-common.js -- fs.readFile is called with this.apkPath as the first argument. The second argument is the callback, whose second argument (here called 'buffer') contains the entire contents of the file.

'buffer' is then passed to the md5 function, which, by the looks of it, duplicates the data in various ways https://github.com/pvorb/node-md5/blob/master/md5.js

[jlipps]

oh right, we do get the md5sum of the apk. good find.

I guess this native node md5 checker is not so awesome. maybe we should change this to use a command-line tool. we could also submit an issue to the md5 node project.

On Dec 12, 2013, at 4:39 PM, samueljmurray notifications@github.com wrote:

Yes, I've only tried one other apk which was 1.9MB and that ran fine.

Looking at the source code, it seems that Appium does read the whole apk into memory at line 170 in lib/devices/android/android-common.js -- fs.readFile is called with this.apkPath as the first argument. The second argument is the callback, whose second argument (here called 'buffer') contains the entire contents of the file.

'buffer' is then passed to the md5 function, which, by the looks of it, duplicates the data in various ways https://github.com/pvorb/node-md5/blob/master/md5.js

— Reply to this email directly or view it on GitHub.

[jlipps]

should now be fixed by @rockbot in master

[lock[bot]]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.