fix: Make sure we close the device proxy if node process gets killed #1153

mykola-mokhnach · 2020-02-04T11:03:23Z

No description provided.

imurchie

Approach seems sound. A couple of comments.

lib/device-connections-factory.js

imurchie · 2020-02-04T11:54:41Z

lib/device-connections-factory.js

+    this.localServer.on('error', (e) => this.log.warn(e.message));
+
+    this.onBeforeProcessExit = () => {
+      if (this.localServer?.listening) {


Make sure that the dependency is set to require at least appium-gulp-plugins@5.1.0 or this won't build.

mykola-mokhnach · 2020-02-04T12:28:24Z

@KazuCocoa Could you please help debugging this code?
Is the connection closed properly for you if Appium process gets terminated with SIGINT?

KazuCocoa · 2020-02-04T14:27:18Z

Okay, will take a look

KazuCocoa · 2020-02-04T16:50:54Z

https://gist.github.com/KazuCocoa/18be61e5a0860eea24760cd4d5158edb

I checked as:

launch appium and establish a real device session
Send SIGINT to the process (Then, Appium prints Received SIGINT - shutting down)
observe the behaviour...

After is this PR. Before is the current master. Exactly The connection to ... has been closed printed as same as before. Is this expected?
(Or should we close Appium immediately before the base driver timeout error and this immediate process close would like to do? )

mykola-mokhnach · 2020-02-04T17:41:07Z

thanks @KazuCocoa
is the same behaviour observed on SIGTERM?

mykola-mokhnach · 2020-02-04T18:22:53Z

@KazuCocoa Would you mind checking appium/appium#13913 instead?

KazuCocoa · 2020-02-05T04:12:45Z

is the same behaviour observed on SIGTERM?

The case was the same as SIGINT

KazuCocoa · 2020-02-05T04:21:38Z

appium/appium#13913 (comment)

mykola-mokhnach · 2020-02-05T07:14:46Z

Thanks @KazuCocoa
I've changed the code to actually wait until the server is closed. Could you please check it one more time (also including normal session deletion for a real device)?

KazuCocoa · 2020-02-05T09:20:27Z

After eae7a59 , driver.quit did not close the listening port, *:xprint-server.
Then, below error happened after .quit and started the same port again.

Selenium::WebDriver::Error::UnknownError: An unknown server-side error occurred while processing the command. Original error: The port #8100 is occupied by an other process. You can either quit that process or select another free port.

~~The behaviour of SIGINT seemed the same.~~ <= this case also kept the *:xprint-server listen

note:
I found appium/appium-ios-device@695da4c#r37127278 (not in this issue)

KazuCocoa

7e17810 bursted CLOSE_WAIT like https://gist.github.com/KazuCocoa/8a7340f01659ee835d9da19c29fef1aa
(and never the connection succeeded)

mykola-mokhnach · 2020-02-06T21:28:26Z

Thanks for checking that @KazuCocoa
Perhaps, you have some ideas on have to make the close server event to not wait for so long? Feel free to add commits to this PR.

KazuCocoa · 2020-02-07T03:26:14Z

Okay. Let me take a look further

KazuCocoa · 2020-02-09T15:58:30Z

note: Current log did not have [iProxy@242bfcc9]. So, probably TCP *:xprint-server (LISTEN) remained after quit or SIGINT as #1153 (comment)

ce00973

[Appium] Received SIGINT - shutting down
[debug] [Appium] Cleaning up 1 active session
[Appium] Closing session, cause was 'The process has received SIGINT signal'
[Appium] Removing session 'a8d7ebea-fd2e-489d-9656-ee63d8b71142' from our master session list
[DevCon Factory] Releasing connections for 242bfcc998fd156df0bd0ad1dde8ab8e0a032114 device on any port number
[DevCon Factory] Found cached connections to release: ["242bfcc998fd156df0bd0ad1dde8ab8e0a032114:8100"]
[DevCon Factory] Releasing the listener for '242bfcc998fd156df0bd0ad1dde8ab8e0a032114:8100'
[iProxy@242bfcc9] The connection to 242bfcc998fd156df0bd0ad1dde8ab8e0a032114 has been closed
[debug] [DevCon Factory] Cached connections count: 0
[debug] [XCUITest] Not clearing log files. Use `clearSystemFiles` capability to turn on.
[iProxy@242bfcc9] The connection to 242bfcc998fd156df0bd0ad1dde8ab8e0a032114 has been closed

429625e

[Appium] Received SIGINT - shutting down
[debug] [Appium] Cleaning up 1 active session
[Appium] Closing session, cause was 'The process has received SIGINT signal'
[Appium] Removing session '500de349-36b9-4762-90a3-c9d5cadb7fdb' from our master session list
[DevCon Factory] Releasing connections for 242bfcc998fd156df0bd0ad1dde8ab8e0a032114 device on any port number
[DevCon Factory] Found cached connections to release: ["242bfcc998fd156df0bd0ad1dde8ab8e0a032114:8100"]
[DevCon Factory] Releasing the listener for '242bfcc998fd156df0bd0ad1dde8ab8e0a032114:8100'
[debug] [DevCon Factory] Cached connections count: 0
[debug] [XCUITest] Not clearing log files. Use `clearSystemFiles` capability to turn on.

KazuCocoa · 2020-02-11T16:56:22Z

lib/device-connections-factory.js

@@ -137,7 +137,7 @@ class DeviceConnectionsFactory {
      promises.push((async () => {
        log.info(`Releasing the listener for '${key}'`);
        try {
-          await this._connectionsMapping[key].iproxy.quit();


fix #1153 (comment)

KazuCocoa · 2020-02-11T16:59:33Z

lib/device-connections-factory.js

-        if (e) {
-          reject(e);
-        } else {
-          this.log.info(`The connection to ${this.udid} has been successfully closed`);


This else never called, and timeout error happened

KazuCocoa · 2020-02-11T17:12:24Z

After SIGINT/quit, node 6810 kazu 26u IPv6 0xa419ae1568d349f3 0t0 TCP *:xprint-server (LISTEN) has gone. Appium can establish the same port.
node 6810 kazu 28u IPv4 0xa419ae1569beb233 0t0 TCP localhost:57030->localhost:xprint-server (ESTABLISHED) also has gone after waiting a couple of seconds after SIGINT/quit.

Current implementation worked on my local for SIGING/quit and establish a new session against the same port after it.
@mykola-mokhnach

mykola-mokhnach · 2020-02-11T17:54:18Z

Current implementation worked on my local for SIGING/quit and establish a new session against the same port after it.

This is great news @KazuCocoa !
Many thanks for your assistance. Lets merge the PR then.

KazuCocoa

Thanks for the cleanup/optimisation after my change!
The latest commit works well :) LGTM (should wait for CI tho)

…ppium#1153)

mykola-mokhnach requested a review from imurchie February 4, 2020 11:03

imurchie reviewed Feb 4, 2020

View reviewed changes

mykola-mokhnach requested review from imurchie and KazuCocoa February 4, 2020 12:27

mykola-mokhnach mentioned this pull request Feb 4, 2020

feat: Make sure all active sessions are cleaned up properly after a termination signal is received appium/appium#13913

Merged

4 tasks

KazuCocoa approved these changes Feb 5, 2020

View reviewed changes

imurchie approved these changes Feb 5, 2020

View reviewed changes

mykola-mokhnach added 11 commits February 5, 2020 22:21

fix: Make sure we close the device proxy if node process gets killed

ab78227

Tune the condition

aa91a70

Add error logging

fa15122

Tune unpipe

4d3538a

Bump the minimum version

ce00973

Make stop to wait until close

320145f

Tune logging

e13b103

logging

4382c3e

Tune logging

a0632c3

tune the handling

7367959

Tune events handling

92dc78b

mykola-mokhnach force-pushed the socket_free branch from bb615bb to 92dc78b Compare February 5, 2020 21:24

mykola-mokhnach added 2 commits February 5, 2020 22:24

Fix rebase

1df69e8

Add return

93f4d13

Add logs

7e17810

KazuCocoa reviewed Feb 6, 2020

View reviewed changes

mykola-mokhnach added 2 commits February 6, 2020 22:18

Init remote socket before local

590361f

Merge branch 'master' into socket_free

55e7052

fix initial create connection error

429625e

mykola-mokhnach and others added 4 commits February 9, 2020 21:53

Bump ios-device

162266c

fix no function error

4b19170

does not await since no response happened in _closeLocalServer

e799d68

call destroy not to remain CLOSED state

6020aa1

KazuCocoa reviewed Feb 11, 2020

View reviewed changes

mykola-mokhnach added 6 commits February 11, 2020 19:00

Simplify stop calls

1a3e482

Simplify close callback

eded66d

get rid of async

53b0c8c

Add debugging

0c521e8

Add timing

5bf6700

Tune the warning

8a6e262

KazuCocoa approved these changes Feb 12, 2020

View reviewed changes

mykola-mokhnach added 3 commits February 12, 2020 07:27

Fix the unit test

cb66fcb

Connect the remote socket in parallel

36888a3

Fix remote socket init

e5936bf

mykola-mokhnach merged commit f1b602f into appium:master Feb 12, 2020

mykola-mokhnach deleted the socket_free branch February 12, 2020 20:26

khanayan123 pushed a commit to khanayan123/appium-xcuitest-driver that referenced this pull request May 10, 2021

fix: Make sure we close the device proxy if node process gets killed (a…

e3f5092

…ppium#1153)

renovate bot mentioned this pull request Jun 6, 2021

Update dependency appium to v1.22.0 tadashi0713/webdriverio-appium-on-docker-android#15

Open

1 task

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: Make sure we close the device proxy if node process gets killed #1153

fix: Make sure we close the device proxy if node process gets killed #1153

mykola-mokhnach commented Feb 4, 2020

imurchie left a comment

imurchie Feb 4, 2020

mykola-mokhnach Feb 4, 2020

mykola-mokhnach commented Feb 4, 2020

KazuCocoa commented Feb 4, 2020

KazuCocoa commented Feb 4, 2020

mykola-mokhnach commented Feb 4, 2020

mykola-mokhnach commented Feb 4, 2020 •

edited

Loading

KazuCocoa commented Feb 5, 2020

KazuCocoa commented Feb 5, 2020

mykola-mokhnach commented Feb 5, 2020

KazuCocoa commented Feb 5, 2020 •

edited

Loading

KazuCocoa left a comment

mykola-mokhnach commented Feb 6, 2020

KazuCocoa commented Feb 7, 2020

KazuCocoa commented Feb 9, 2020

KazuCocoa Feb 11, 2020

KazuCocoa Feb 11, 2020

KazuCocoa commented Feb 11, 2020

mykola-mokhnach commented Feb 11, 2020

KazuCocoa left a comment

fix: Make sure we close the device proxy if node process gets killed #1153

fix: Make sure we close the device proxy if node process gets killed #1153

Conversation

mykola-mokhnach commented Feb 4, 2020

imurchie left a comment

Choose a reason for hiding this comment

imurchie Feb 4, 2020

Choose a reason for hiding this comment

mykola-mokhnach Feb 4, 2020

Choose a reason for hiding this comment

mykola-mokhnach commented Feb 4, 2020

KazuCocoa commented Feb 4, 2020

KazuCocoa commented Feb 4, 2020

mykola-mokhnach commented Feb 4, 2020

mykola-mokhnach commented Feb 4, 2020 • edited Loading

KazuCocoa commented Feb 5, 2020

KazuCocoa commented Feb 5, 2020

mykola-mokhnach commented Feb 5, 2020

KazuCocoa commented Feb 5, 2020 • edited Loading

KazuCocoa left a comment

Choose a reason for hiding this comment

mykola-mokhnach commented Feb 6, 2020

KazuCocoa commented Feb 7, 2020

KazuCocoa commented Feb 9, 2020

KazuCocoa Feb 11, 2020

Choose a reason for hiding this comment

KazuCocoa Feb 11, 2020

Choose a reason for hiding this comment

KazuCocoa commented Feb 11, 2020

mykola-mokhnach commented Feb 11, 2020

KazuCocoa left a comment

Choose a reason for hiding this comment

mykola-mokhnach commented Feb 4, 2020 •

edited

Loading

KazuCocoa commented Feb 5, 2020 •

edited

Loading