search

mobile-dev-inc / maestro

Painless Mobile UI Automation
https://maestro.mobile.dev/
Apache License 2.0
5.78k stars 270 forks source link

[1.31.0, 1.30.4] `xcuitest.XCTestDriverClient$XCTestDriverUnreachable` #1299

Open denil-ct opened 1 year ago

denil-ct commented 1 year ago

Describe the bug When running maestro test, I'm getting an exception

xcuitest.XCTestDriverClient$XCTestDriverUnreachable: Failed to reach XCUITest Server in restart
    at xcuitest.XCTestDriverClient.restartXCTestRunnerService(XCTestDriverClient.kt:52)
    at ios.xctest.XCTestIOSDevice.open(XCTestIOSDevice.kt:33)
    at ios.LocalIOSDevice.open(LocalIOSDevice.kt:25)
    at maestro.drivers.IOSDriver.open(IOSDriver.kt:84)
    at maestro.Maestro$Companion.ios(Maestro.kt:579)
    at maestro.cli.session.MaestroSessionManager.createIOS(MaestroSessionManager.kt:329)
    at maestro.cli.session.MaestroSessionManager.createMaestro(MaestroSessionManager.kt:157)
    at maestro.cli.session.MaestroSessionManager.access$createMaestro(MaestroSessionManager.kt:50)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:82)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:81)
    at maestro.cli.db.KeyValueStore.withExclusiveLock(KeyValueStore.kt:37)
    at maestro.cli.session.SessionStore.withExclusiveLock(SessionStore.kt:74)
    at maestro.cli.session.MaestroSessionManager.newSession(MaestroSessionManager.kt:81)
    at maestro.cli.session.MaestroSessionManager.newSession$default(MaestroSessionManager.kt:58)
    at maestro.cli.command.TestCommand.call(TestCommand.kt:126)
    at maestro.cli.command.TestCommand.call(TestCommand.kt:44)
    at picocli.CommandLine.executeUserObject(CommandLine.java:1933)
    at picocli.CommandLine.access$1200(CommandLine.java:145)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2332)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2326)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2291)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2159)
    at maestro.cli.DisableAnsiMixin$Companion.executionStrategy(DisableAnsiMixin.kt:22)
    at picocli.CommandLine.execute(CommandLine.java:2058)
    at maestro.cli.AppKt.main(App.kt:131)

Also, you can see the maestro-driver app getting installed after maestro exit from command line.

To Reproduce

Expected behavior Launch the app and execute the tests.

Screenshots NA

Environment information (please complete the following information):

Workspace (if applicable) NA

Bugreport output (if applicable) Archive.zip

Additional context NA

hackdie commented 1 year ago

https://mobile-dev-inc.slack.com/archives/C041FU72T54/p1689668746779869

im having same issue, hope they can fix it soon 🙏🏼

jmichie-c commented 1 year ago

Also having same issue: https://mobile-dev-inc.slack.com/archives/C041FU72T54/p1691417461247089

denil-ct commented 1 year ago

Issue still exists on 1.31.0

xcuitest.XCTestDriverClient$XCTestDriverUnreachable: Failed to reach XCUITest Server in restart
    at xcuitest.XCTestDriverClient.restartXCTestRunnerService(XCTestDriverClient.kt:51)
    at ios.xctest.XCTestIOSDevice.open(XCTestIOSDevice.kt:31)
    at ios.LocalIOSDevice.open(LocalIOSDevice.kt:25)
    at maestro.drivers.IOSDriver.open(IOSDriver.kt:76)
    at maestro.Maestro$Companion.ios(Maestro.kt:567)
    at maestro.cli.session.MaestroSessionManager.createIOS(MaestroSessionManager.kt:308)
    at maestro.cli.session.MaestroSessionManager.createMaestro(MaestroSessionManager.kt:153)
    at maestro.cli.session.MaestroSessionManager.access$createMaestro(MaestroSessionManager.kt:49)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:81)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:80)
    at maestro.cli.db.KeyValueStore.withExclusiveLock(KeyValueStore.kt:37)
    at maestro.cli.session.SessionStore.withExclusiveLock(SessionStore.kt:74)
    at maestro.cli.session.MaestroSessionManager.newSession(MaestroSessionManager.kt:80)
    at maestro.cli.session.MaestroSessionManager.newSession$default(MaestroSessionManager.kt:57)
    at maestro.cli.command.TestCommand.call(TestCommand.kt:137)
    at maestro.cli.command.TestCommand.call(TestCommand.kt:46)
    at picocli.CommandLine.executeUserObject(CommandLine.java:1933)
    at picocli.CommandLine.access$1200(CommandLine.java:145)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2332)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2326)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2291)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2159)
    at maestro.cli.DisableAnsiMixin$Companion.executionStrategy(DisableAnsiMixin.kt:22)
    at picocli.CommandLine.execute(CommandLine.java:2058)
    at maestro.cli.AppKt.main(App.kt:126)

Logs Archive.zip

raulriera commented 1 year ago

Having this issue only when upgrading to the latests macOS Venture https://mobile-dev-inc.slack.com/archives/C041FU72T54/p1693599067865679

larryng commented 1 year ago

I was able to workaround the issue locally by prepending to /etc/hosts

::1 localhost

as the issue seems to be with connecting to the XCTestHTTPServer using IPv4? 🤷‍♂️

For posterity, LocalXCTestInstaller#subTreeOfRunnerApp() was the step that's failing, throwing

java.net.ConnectException: Failed to connect to localhost/127.0.0.1:22087
    at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:297)
    at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:207)
    at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226)
    at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106)
    at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74)
    at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255)
    at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
    at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
    at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
    at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
    at xcuitest.installer.LocalXCTestInstaller.subTreeOfRunnerApp(LocalXCTestInstaller.kt:138)
    at xcuitest.installer.LocalXCTestInstaller.access$subTreeOfRunnerApp(LocalXCTestInstaller.kt:20)
    at xcuitest.installer.LocalXCTestInstaller$ensureOpen$2.invoke(LocalXCTestInstaller.kt:108)
    at xcuitest.installer.LocalXCTestInstaller$ensureOpen$2.invoke(LocalXCTestInstaller.kt:105)
    at maestro.utils.MaestroTimer.retryUntilTrue(MaestroTimer.kt:33)
    at xcuitest.installer.LocalXCTestInstaller.ensureOpen(LocalXCTestInstaller.kt:105)
    at xcuitest.installer.LocalXCTestInstaller.start(LocalXCTestInstaller.kt:83)
    at xcuitest.XCTestDriverClient.restartXCTestRunnerService(XCTestDriverClient.kt:50)
    at ios.xctest.XCTestIOSDevice.open(XCTestIOSDevice.kt:33)
    at ios.LocalIOSDevice.open(LocalIOSDevice.kt:25)
    at maestro.drivers.IOSDriver.open(IOSDriver.kt:84)
    at maestro.Maestro$Companion.ios(Maestro.kt:579)
    at maestro.cli.session.MaestroSessionManager.createIOS(MaestroSessionManager.kt:331)
    at maestro.cli.session.MaestroSessionManager.createMaestro(MaestroSessionManager.kt:159)
    at maestro.cli.session.MaestroSessionManager.access$createMaestro(MaestroSessionManager.kt:51)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:83)
    at maestro.cli.session.MaestroSessionManager$newSession$session$1.invoke(MaestroSessionManager.kt:82)
    at maestro.cli.db.KeyValueStore.withExclusiveLock(KeyValueStore.kt:37)
    at maestro.cli.session.SessionStore.withExclusiveLock(SessionStore.kt:74)
    at maestro.cli.session.MaestroSessionManager.newSession(MaestroSessionManager.kt:82)
    at maestro.cli.command.StudioCommand.call(StudioCommand.kt:36)
    at maestro.cli.command.StudioCommand.call(StudioCommand.kt:18)
    at picocli.CommandLine.executeUserObject(CommandLine.java:1933)
    at picocli.CommandLine.access$1200(CommandLine.java:145)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2332)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2326)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2291)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2159)
    at maestro.cli.DisableAnsiMixin$Companion.executionStrategy(DisableAnsiMixin.kt:22)
    at picocli.CommandLine.execute(CommandLine.java:2058)
    at maestro.cli.AppKt.main(App.kt:131)
Caused by: java.net.ConnectException: Connection refused
    at java.base/sun.nio.ch.Net.pollConnect(Native Method)
    at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
    at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:542)
    at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:597)
    at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
    at java.base/java.net.Socket.connect(Socket.java:633)
    at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:128)
    at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:295)
    ... 46 more

(your stacktrace may differ as this contains my local changes)

However, making the same request with curl worked fine:

curl "http://localhost:22087/subTree?appId=com.apple.springboard"

Inspecting sudo tcpdump --interface lo0 port 22087 reveals the difference between the Maestro vs. curl requests:

# Maestro
09:55:35.662699 IP localhost.49365 > localhost.22087: Flags [S], seq 2750286120, win 65535, options [mss 16344,nop,wscale 6,nop,nop,TS val 454807741 ecr 0,sackOK,eol], length 0
09:55:35.662722 IP localhost.22087 > localhost.49365: Flags [R.], seq 0, ack 2750286121, win 0, length 0
09:55:35.771654 IP localhost.49368 > localhost.22087: Flags [S], seq 2219560961, win 65535, options [mss 16344,nop,wscale 6,nop,nop,TS val 149277760 ecr 0,sackOK,eol], length 0
09:55:35.771682 IP localhost.22087 > localhost.49368: Flags [R.], seq 0, ack 2219560962, win 0, length 0
09:55:35.873258 IP localhost.49369 > localhost.22087: Flags [S], seq 227206071, win 65535, options [mss 16344,nop,wscale 6,nop,nop,TS val 1757541771 ecr 0,sackOK,eol], length 0
...
# curl
09:55:35.996301 IP6 localhost.49372 > localhost.22087: Flags [S], seq 4067101485, win 65535, options [mss 16324,nop,wscale 6,nop,nop,TS val 2750702838 ecr 0,sackOK,eol], length 0
09:55:35.996474 IP6 localhost.22087 > localhost.49372: Flags [S.], seq 1383336803, ack 4067101486, win 65535, options [mss 16324,nop,wscale 6,nop,nop,TS val 373980162 ecr 2750702838,sackOK,eol], length 0
09:55:35.996482 IP6 localhost.49372 > localhost.22087: Flags [.], ack 1, win 6371, options [nop,nop,TS val 2750702838 ecr 373980162], length 0
09:55:35.996486 IP6 localhost.22087 > localhost.49372: Flags [.], ack 1, win 6371, options [nop,nop,TS val 373980162 ecr 2750702838], length 0
09:55:35.996503 IP6 localhost.49372 > localhost.22087: Flags [P.], seq 1:115, ack 1, win 6371, options [nop,nop,TS val 2750702838 ecr 373980162], length 114
...

I'm not going to pretend I know what I'm looking at, other than the IP vs IP6. Hopefully this helps y'all uncover the root cause.

denil-ct commented 1 year ago

@larryng it seems maestro keeps resetting the incoming connection, whereas in the curl it sends the ack and establishes a TCP connection and proceeds to receive data. If the localhost is pointed to ipv4, is the curl request working?

larryng commented 1 year ago

If the localhost is pointed to ipv4, is the curl request working?

Originally my /etc/hosts only had 127.0.0.1 localhost and the curl request did work, although it still uses IPv6 (maybe curl has special support for localhost?). However, the curl request fails if using the -4, --ipv4 flag to force IPv4.

denil-ct commented 1 year ago

I seem to have mixed results with the workaround. It started to work fine at first, but after opening a tcpdump session, it stopped working :(

Will have to check how it behaves in CI.

amanjeetsingh150 commented 1 year ago

but after opening a tcpdump session, it stopped working :(

Can you check if that doesn't reset your /etc/hosts file. You should have ::1 localhost to ensure localhost ipv6 gets resolved

denil-ct commented 1 year ago

Yup, it still had it. This was the state it was in.

::1             localhost
127.0.0.1   localhost
255.255.255.255 broadcasthost

I am on version 1.32.0