Java Client 6.0.0: End Of Stream WebDriverException with getContext() sporadically

[bennid]

Description

Wasn't able to reproduce this using Java Client 6.0.0-BETA5. Essentially I have a 'keepalive' that every 40 seconds will make a 'getContext()' call in order to make sure a session doesn't disconnect while doing processing on another phone. Up until Java Client 6.0.0 "Stable" this worked fine. After trying out 6.0.0, ran into this

Environment

• java client build version or git revision if you use some shapshot: 6.0.0 Stable
• Appium server version or git revision if you use some shapshot: 1.7.2
• Desktop OS/version used to run Appium if necessary: mac ox 10.13.4
• Node.js version (unless using Appium.app|exe) or Appium CLI or Appium.app|exe: 8.11.1
• Mobile platform/version under test: Android Emulator 5.1
• Real device or emulator/simulator: Emulator

Details

This is also going through a selenium grid running selenium-server-standalone 3.11.0

Code To Reproduce Issue [ Good To Have ]

for (int i = 0; i < 3; i++) {
    String context = appiumDriver.getContext();
    System.out.println(new Date() + " -- Iteration " + i + " :: " + context);
    Thread.sleep(30000);
}

Exception stacktraces

https://gist.github.com/bennid/6972a40c7f54689582703a768de5a710

Link to Appium logs

The appium server never saw the request come in, and only contains initial session creation, and a single getContext() call.

2018-06-01 19:44:27:292 - [HTTP] --> GET /wd/hub/session/39e20d3c-d60f-41e2-9609-88207810e055/context {}
2018-06-01 19:44:27:294 - [debug] [MJSONWP] Calling AppiumDriver.getCurrentContext() with args: ["39e20d3c-d60f-41e2-9609-88207810e055"]
2018-06-01 19:44:27:299 - [debug] [MJSONWP] Responding to client with driver.getCurrentContext() result: "NATIVE_APP"
2018-06-01 19:44:27:300 - [HTTP] <-- GET /wd/hub/session/39e20d3c-d60f-41e2-9609-88207810e055/context 200 8 ms - 84 
2018-06-01 19:44:32:277 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:32:277 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:32:290 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:32:291 - [HTTP] <-- GET /wd/hub/status 200 14 ms - 83 
2018-06-01 19:44:37:299 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:37:302 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:37:312 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:37:312 - [HTTP] <-- GET /wd/hub/status 200 13 ms - 83 
2018-06-01 19:44:42:320 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:42:320 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:42:333 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:42:334 - [HTTP] <-- GET /wd/hub/status 200 14 ms - 83 
2018-06-01 19:44:47:342 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:47:342 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:47:351 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:47:352 - [HTTP] <-- GET /wd/hub/status 200 10 ms - 83 
2018-06-01 19:44:52:368 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:52:368 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:52:378 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:52:379 - [HTTP] <-- GET /wd/hub/status 200 11 ms - 83 
2018-06-01 19:44:57:355 - [HTTP] --> GET /wd/hub/session/39e20d3c-d60f-41e2-9609-88207810e055/appium/device/current_activity {}
2018-06-01 19:44:57:356 - [debug] [MJSONWP] Calling AppiumDriver.getCurrentActivity() with args: ["39e20d3c-d60f-41e2-9609-88207810e055"]
2018-06-01 19:44:57:357 - [debug] [ADB] Getting focused package and activity
2018-06-01 19:44:57:358 - [debug] [ADB] Getting connected devices...
2018-06-01 19:44:57:383 - [debug] [ADB] 1 device(s) connected
2018-06-01 19:44:57:383 - [debug] [ADB] Running '/Users/bedouglas/build_tools/android-sdk-macosx-r24.4.1/platform-tools/adb' with args: ["-P",5037,"-s","emulator-5554","shell","dumpsys","window","windows"]
2018-06-01 19:44:57:388 - [HTTP] --> GET /wd/hub/status {}
2018-06-01 19:44:57:388 - [debug] [MJSONWP] Calling AppiumDriver.getStatus() with args: []
2018-06-01 19:44:57:399 - [debug] [MJSONWP] Responding to client with driver.getStatus() result: {"build":{"version":"1.7.2","revision":null}}
2018-06-01 19:44:57:401 - [HTTP] <-- GET /wd/hub/status 200 12 ms - 83 
2018-06-01 19:44:57:420 - [debug] [MJSONWP] Responding to client with driver.getCurrentActivity() result: "my.company.app.ui.main.StartupActivity"
2018-06-01 19:44:57:421 - [HTTP] <-- GET /wd/hub/session/39e20d3c-d60f-41e2-9609-88207810e055/appium/device/current_activity 200 65 ms - 128 

[bennid]

NOTE 1: Catching the exception and retrying worked
NOTE 2: This also happened on appiumDriver.getDeviceTime();

[mykola-mokhnach]

@bennid Please try if #928 works for you

[saikrishna321]

@bennid ping

@mykola-mokhnach i tested this in my local and it works fine. Even i bumped at the same issue on my machine.

[mykola-mokhnach]

I'm going to close the issue after the fix is present in BETA

[SrinivasanTarget]

@bennid Fix is in 6.1.0.