Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory #13631

Closed
dennybritz opened this issue Nov 25, 2019 · 14 comments
Closed

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory #13631

dennybritz opened this issue Nov 25, 2019 · 14 comments
Assignees
@mykola-mokhnach
Labels
Bug a problem that needs fixing DriverIssue nonspecific driver issue

Comments

@dennybritz
Copy link

The problem

Same as #13321 and #13074

Appium crashes after some time with FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory due to memory leak. Process memory is continuously increasing.

I saw this problem with the latest stable version, then upgraded to appium@beta as suggested in the other issue. The problem is still the same.

Environment

  • Appium version (or git revision) that exhibits the issue: 1.16.0-beta.2
  • Last Appium version that did not exhibit the issue (if applicable): N/A
  • Desktop OS/version used to run Appium: macOS 10.15.1
  • Node.js version (unless using Appium.app|exe): v13.1.0
  • Npm or Yarn package manager: npm 6.13.1
  • Mobile platform/version under test: iOS 12.4
  • Real device or emulator/simulator: Real Device
  • Appium CLI or Appium.app|exe: CLI

Details

The application is taking screenshots with get_screenshot_as_file in a loop, same as the other issue(s) linked above. Here's a heap snapshot taken a 10 minutes into the run with memory usage already at several GB:

Heap.20191125.115127.20733.0.006.heapsnapshot.zip

I took a brief look at the dump and it seems like all screenshots are left in memory?

Link to Appium logs

https://gist.github.com/dennybritz/c727f4ad03379340713fc3d3a19b0dc5
@mykola-mokhnach mykola-mokhnach added the Bug a problem that needs fixing label Nov 25, 2019
@mykola-mokhnach mykola-mokhnach mentioned this issue Nov 25, 2019
Merged
@mykola-mokhnach
Copy link
Collaborator

@dennybritz Can you please apply the patch appium/appium-base-driver#370 to your local sources and try again?

@dennybritz
Copy link
Author

I applied the changes to /usr/local/lib/node_modules/appium/node_modules/appium-base-driver but I don't think that fixed it, the memory usage still keeps increasing.

@mykola-mokhnach
Copy link
Collaborator

Can you provide the updated snapshot?

@dennybritz
Copy link
Author

Here's a snapshot:
Heap.20191125.225624.40557.0.002.heapsnapshot.zip

@mykola-mokhnach
Copy link
Collaborator

The recent snapshot seems to be the same.

Make sure the appium-base-driver module is deduplicated. It is necessary to make sure the instance is used by both the umbrella driver (the main Appium module) and appium-xcuitest-driver. #13321 (comment) contains more details on how to deploy the changes locally

@dennybritz
Copy link
Author

dennybritz commented Nov 26, 2019 •
edited
Loading

I haven't been able to test this. I don't know why patching the module didn't work, but I tried building Appium from scratch and linking in the appium-base-driver module, but when doing that, I get the following error when trying to execute commands:

[debug] [BaseDriver] Event 'wdaSessionStarted' logged at 1574734188075 (11:09:48 GMT+0900 (Japan Standard Time))
[debug] [BaseDriver] Event 'wdaStarted' logged at 1574734188075 (11:09:48 GMT+0900 (Japan Standard Time))
[XCUITest] Skipping setting of the initial display orientation. Set the "orientation" capability to either "LANDSCAPE" or "PORTRAIT", if this is an undesired behavior.
[debug] [BaseDriver] Event 'orientationSet' logged at 1574734188076 (11:09:48 GMT+0900 (Japan Standard Time))
[Appium] New XCUITestDriver session created successfully, session 8b27b9bf-ba68-4322-b015-513af55d1680 added to master session list
[Appium] Closing session, cause was 'Unexpected shutdown'
[Appium] Removing session 8b27b9bf-ba68-4322-b015-513af55d1680 from our master session list
[debug] [BaseDriver] Event 'newSessionStarted' logged at 1574734188078 (11:09:48 GMT+0900 (Japan Standard Time))
[debug] [W3C (8b27b9bf)] Cached the protocol value 'W3C' for the new session 8b27b9bf-ba68-4322-b015-513af55d1680
[debug] [W3C (8b27b9bf)] Responding to client with driver.createSession() result: {"capabilities":{"webStorageEnabled":false,"locationContextEnabled":false,"browserName":"","platform":"MAC","javascriptEnabled":true,"databaseEnabled":false,"takesScreenshot":true,"networkConnectionEnabled":false,"platformName":"iOS","automationName":"xcuitest","bundleId":"XX","deviceName":"Denny's iPad","newCommandTimeout":14400,"platformVersion":"12.1","showXcodeLog":true,"udid":"28a137d218a843ebf53e88684179612b1b7ef9e8","xcodeOrgId":"XXX","xcodeSigningId":"iPhone Developer"}}

[HTTP] <-- POST /wd/hub/session 200 13669 ms - 579
[HTTP] 
[HTTP] --> GET /wd/hub/session/8b27b9bf-ba68-4322-b015-513af55d1680/screenshot
[HTTP] {}

[debug] [W3C (36f3e66a)] Encountered internal error running command: NoSuchDriverError: A session is either terminated or not started
[debug] [W3C (36f3e66a)]     at asyncHandler (/Users/dennybritz/github/appium-base-driver/lib/protocol/protocol.js:252:15)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/lib/protocol/protocol.js:432:15
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/route.js:137:13)
[debug] [W3C (36f3e66a)]     at Route.dispatch (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/route.js:112:3)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:281:22
[debug] [W3C (36f3e66a)]     at param (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:354:14)
[debug] [W3C (36f3e66a)]     at param (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:365:14)
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:410:3)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at logger (/Users/dennybritz/github/appium-base-driver/node_modules/morgan/index.js:144:5)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at jsonParser (/Users/dennybritz/github/appium-base-driver/node_modules/body-parser/lib/types/json.js:110:7)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:91:12)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:91:12)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at methodOverride (/Users/dennybritz/github/appium-base-driver/node_modules/method-override/index.js:65:14)
[HTTP] <-- GET /wd/hub/session/36f3e66a-2f3f-446d-8229-08056ee2aacc/screenshot 404 24 ms - 4039
[HTTP] 
[HTTP] --> GET /wd/hub/session/36f3e66a-2f3f-446d-8229-08056ee2aacc/screenshot
[HTTP] {}
[debug] [W3C (36f3e66a)] Encountered internal error running command: NoSuchDriverError: A session is either terminated or not started
[debug] [W3C (36f3e66a)]     at asyncHandler (/Users/dennybritz/github/appium-base-driver/lib/protocol/protocol.js:252:15)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/lib/protocol/protocol.js:432:15
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/route.js:137:13)
[debug] [W3C (36f3e66a)]     at Route.dispatch (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/route.js:112:3)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:281:22
[debug] [W3C (36f3e66a)]     at param (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:354:14)
[debug] [W3C (36f3e66a)]     at param (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:365:14)
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:410:3)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at logger (/Users/dennybritz/github/appium-base-driver/node_modules/morgan/index.js:144:5)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at jsonParser (/Users/dennybritz/github/appium-base-driver/node_modules/body-parser/lib/types/json.js:110:7)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:95:5)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:91:12)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at Layer.handle [as handle_request] (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/layer.js:91:12)
[debug] [W3C (36f3e66a)]     at trim_prefix (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:317:13)
[debug] [W3C (36f3e66a)]     at /Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:284:7
[debug] [W3C (36f3e66a)]     at Function.process_params (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:335:12)
[debug] [W3C (36f3e66a)]     at next (/Users/dennybritz/github/appium-base-driver/node_modules/express/lib/router/index.js:275:10)
[debug] [W3C (36f3e66a)]     at methodOverride (/Users/dennybritz/github/appium-base-driver/node_modules/method-override/index.js:65:14)

@mykola-mokhnach
Copy link
Collaborator

The log above seems odd. I'll spend some time to check the stuff locally, although I cannot say how long it would take

@dennybritz
Copy link
Author

dennybritz commented Nov 26, 2019 •
edited
Loading

For what it's worth, I did built the 1.16.0-beta.2 version locally and it worked fine, but once I link in the updated appium-base-driver module I get the above and it immediately closes the session.

@mykola-mokhnach
Copy link
Collaborator

mykola-mokhnach commented Nov 26, 2019 •
edited
Loading

Try to also apply the changes from #13635 to the main module (except of version bump in package.js)

This should help

@dennybritz
Copy link
Author

That seems to have fixed the session close issue but the memory leak problem is still there:

Heap.20191126.165021.62039.0.003.heapsnapshot.zip

@mykola-mokhnach mykola-mokhnach mentioned this issue Nov 26, 2019
Merged
@mykola-mokhnach
Copy link
Collaborator

Thanks for your patience. We really appreciate your support. Please try if there are still memory leaks after appium/appium-base-driver#371 is applied

@dennybritz
Copy link
Author

Yep, this seems to fix it! 🎉

@mykola-mokhnach
Copy link
Collaborator

Perfect. We'll merge the changes by the end of the day. Although, it will take some time until new versions of all components will be published (I'm not sure if Appium 1.16 is going to include this change)

CC @dpgraham

@mykola-mokhnach mykola-mokhnach self-assigned this Nov 26, 2019
@mykola-mokhnach mykola-mokhnach added the DriverIssue nonspecific driver issue label Nov 26, 2019
@mykola-mokhnach
Copy link
Collaborator

The fix has been published to beta

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mykola-mokhnach mykola-mokhnach

Labels
Bug a problem that needs fixing DriverIssue nonspecific driver issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dennybritz @mykola-mokhnach