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.

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

An unknown server-side error occurred while processing the command. Original error: Could not proxy command to remote server. Original error: Error: read ECONNRESET #11628

Closed
MummanaSubramanya opened this issue Nov 5, 2018 · 30 comments

Comments

@MummanaSubramanya
Copy link

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

The problem

Server crashes without any information at any random line of c# code

Environment

  • Appium version (or git revision) that exhibits the issue: 1.9.1 and 1.9.2-beta
  • Last Appium version that did not exhibit the issue (if applicable): 1.8.1
  • Desktop OS/version used to run Appium:
  • Node.js version (unless using Appium.app|exe):
  • Mobile platform/version under test: Android 8
  • Real device or emulator/simulator: Real
  • Appium CLI or Appium.app|exe: CLI and desktop

Details

{"platformName":"Android","automationName":"UIAutomator2","platformVersion":"8.0","deviceName":"Galaxy S8","printPageSourceOnFindFailure":true,"appPackage":"com.xxx.xxx","appActivity":".MainActivity","autoWebview":true,"nativeWebScreenshot":true,"newCommandTimeout":500,"chromedriverUseSystemExecutable":false}

Link to Appium logs

https://gist.github.com/MummanaSubramanya/e018a8952b6fc82de31b1caea17e8e4a

https://gist.github.com/MummanaSubramanya/0ae2fee349d23bda9b9646b243a1291e

Code To Reproduce Issue [ Good To Have ]

randomly fails at any line of code.

Exception

OpenQA.Selenium.WebDriverException: An unknown server-side error occurred while processing the command. Original error: Could not proxy command to remote server. Original error: Error: read ECONNRESET

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

its able to find the element but in message body it says chrome is unreachable.

@mykola-mokhnach

This comment has been minimized.

Copy link
Collaborator

@mykola-mokhnach mykola-mokhnach commented Nov 5, 2018

This looks like chromedriver issue. Please attach the logcat output. Perhaps it contains some useful information

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

adhlogcat-Error.txt

Attaching the logcat

@mykola-mokhnach

This comment has been minimized.

Copy link
Collaborator

@mykola-mokhnach mykola-mokhnach commented Nov 5, 2018

Are you sure this is the correct log? I don't observe any errors there. Also make sure the chromedriver binary is at most recent version

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

https://gist.github.com/MummanaSubramanya/93cee47cc30d67780acc94343e8edf57.

chrome driver log for reference .

adhlogcat-Error.txt
here is the latest adb log

@mykola-mokhnach

This comment has been minimized.

Copy link
Collaborator

@mykola-mokhnach mykola-mokhnach commented Nov 5, 2018

Again, this is not something, that can be fixed in Appium. Appium simply proxies the request to chromedriver and the latter stops responding unexpectedly.

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

Ah! @MummanaSubramanya in your appium logs on line 14 (of the second run you posted) I saw the following:
[BaseDriver] Shutting down because we waited 500 seconds for a command

What is happening is your script is pausing for 500 seconds. In the logs you posted, this occurred when you send the hideKeyboard command. Appium must be failing to hide the keyboard and never returns. After 500 seconds, the appium server is deciding that your app is stuck and it shuts down the session. It then shuts down the session, closing chromedriver on the device, but responds with a 200 successful response for hiding keyboard. Your app is then continuing, but the session has been deleted so the chromedriver proxy port it was using no longer exists and your getting this error.

Could you post more appium logs so we could see if this is related to your hideKeyboard or it could be something else.

@mykola-mokhnach in this case, appium should be responding to the POST to hideKeyboard with an error rather than 200 right? And the following requests all use the sessionId of a session which should have been deleted, but instead of responding about a deleted session, appium is still trying to forward commands to a non-existent chromedriver.

@mykola-mokhnach

This comment has been minimized.

Copy link
Collaborator

@mykola-mokhnach mykola-mokhnach commented Nov 5, 2018

@Jonahss The hideKeyboard method does not verify whether the keyboard was actually hidden, but rather just presses back button and exists if dumpsys inputmethod allows this. Shall we replace pressing back button with escape and add the verification of keyboard closed event?

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

@mykola-mokhnach I suspect that the issue that MummanaSubramanya is running into may be unrelated to hide keyboard, and could be many commands. I was just wondering if we could improve the error handling. It looks like the default 500 second inactivity timeout is being hit. When the timeout happens, new commands using the old session ID should fail, but appium is allowing them and forwarding to chromedriver.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss @mykola-mokhnach hide keyboard is not the issue I have wriiten a function where it enters the text and hides the keyboard if exists else it will catch the exception and goes to next statement.

Its not related to keyboard at all if see you another log you can see similar issue but at different step.
And before failing it never waits for 500 secs it abruptly fails unknowingly.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

https://gist.github.com/MummanaSubramanya/93cee47cc30d67780acc94343e8edf57 in this log im trying to clikc on profile button but it fails abruptly. I dint faced this issue with 1.8.1 -- android 6. The tests fails when I run them in bulk. out of 10 tests first 6-7 will run fine and then it starts failing. This logs has chromedriver log enabaled. could you guys have a look @mykola-mokhnach @Jonahss

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

@MummanaSubramanya could you post the logs including a few minutes earlier than the link you just provided?
The errors you are seeing happen after appium shuts down the chromedriver. I am trying to find out why appium shuts down the chromedriver and I think I have an idea.

Could you provide logs maybe 5 minutes earlier than the logs you just sent?

@MummanaSubramanya

This comment has been minimized.

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

@MummanaSubramanya Thank you.

I notice on these logs that on line 85, we see this again:
[35m[BaseDriver]�[39m Shutting down because we waited 500 seconds for a command
That is definitely a clue to whatever the issue is. I can't say yet what it is, but I have some theories. Could you provide much more of the logs? I'd like to see a couple commands that come before that happens.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss : okay sure give me a minute

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

@MummanaSubramanya Ah, the most recent one you posted, I need logs much much higher up.
The pattern I have been seeing in your logs is like this:

--> POST some command
.....
Shutting down because we waited 500 seconds for a command
.....
Closing session
.....
Encountered internal error running command: ProxyRequestError: Could not proxy command to remote server.
.....
Encountered internal error running command: ProxyRequestError: Could not proxy command to remote server.
......
Encountered internal error running command: ProxyRequestError: Could not proxy command to remote server.

After the Shutting down because we waited 500 seconds for a command, from then on, every single command fails with
Encountered internal error running command: ProxyRequestError: Could not proxy command to remote server.

I would like to see what happens in the logs before the Shutting down because we waited 500 seconds for a command log line. I need to see a lot of logs before it though, probably 300 lines before. Is that something you can get for me? Even from the beginning is OK, I'll just scroll through the long file.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss : https://gist.github.com/MummanaSubramanya/fbd6112bcc3abba2ceb942488b3736c3 here you as you requested. At line 158 shutdown happens

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 5, 2018

Thank you, that was good. Your test looks completely normal before the 500 second timeout is hit, and you were right that it does not seem related to hideKeyboard.

For some reason, appium is hitting its 500 second new command timeout.

I would assume this is because there is a 500 second pause between commands sent to appium, or there is some issue with the way appium counts the seconds for timeout.

Either way, we can test this. Try adding the following desired capability to your test, in order to set the timeout to about 30 minutes

newCommandTimeout: 2000

If you run with that, we can see if your tests all finish without hitting this error.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

sure let me try with that.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss : nope 2 tests failed because of same error.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 5, 2018

@Jonahss : https://gist.github.com/MummanaSubramanya/4b25ba9f9a64ab0f26c375835a847e66 here is the new gist of the appium logs. check at line 41

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 6, 2018

@Jonahss : Did you got a chance to look at it ?

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 6, 2018

Did the tests get further than last time?
Try setting the timeout to 10000, and we'll see if we stop for 2.7 hours.
While running this test, you could also check to make sure that there isn't actually a 2.7 hour long pause, right? If not, then we will need to look at how appium keeps track of the command timeout.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 6, 2018

@Jonahss after increasing the timeout from 2000 --> 20000 I'm no more getting the error. I ran multiple times and all tests are passed. Seems like there is some issue with newCommandTimeOut.

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 6, 2018

I will never put or have the pause of 2.7hrs in my tests ;-)

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 6, 2018

Ok so we found a super long timeout that lets all your tests pass. When you had the timeout set to 2000 some of your tests failed, but you definitely didn't have the app freeze for a full 30 minutes during the test.

I think you're right that there could be something wrong with how the newCommandTimeout is calculated.

I'm glad your tests are at least succeeding now. I can try to reproduce this issue but it may take a lot of time for me to try to reproduce. If you wanted to put in the time to help, maybe you could try making a sample test you could share with me that reproduces the issue.
I am almost certain that the fact that we are using Chromedriver is related.
Maybe you could use a sample website and try to reduce the number and complexity of tests in your test suite until we find a minimum number of tests to reproduce this?

@MummanaSubramanya

This comment has been minimized.

Copy link
Author

@MummanaSubramanya MummanaSubramanya commented Nov 7, 2018

@Jonahss: sure will provide you the details.

@Jonahss

This comment has been minimized.

Copy link
Contributor

@Jonahss Jonahss commented Nov 8, 2018

Thanks!

@mykola-mokhnach

This comment has been minimized.

Copy link
Collaborator

@mykola-mokhnach mykola-mokhnach commented Nov 30, 2018

Closed as inactive

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.