search

appium / appium-inspector

A GUI inspector for mobile apps and more, powered by a (separately installed) Appium server
https://appium.github.io/appium-inspector/
Other
1.13k stars 282 forks source link

bug: Inspector hangs and app freezes as soon as session begins #1386

Closed tking16 closed 6 months ago

tking16 commented 6 months ago

Is this an issue specifically with Appium Inspector?

Is there an existing issue for this?

Current Behavior

Please see the screenshot, the app inspector will just load like that for eternity, I can't tap any buttons on the app either as it's completely frozen so I need to force close it. I also need to force close Appium Inspector as the 'x' button does nothing when it's like this

Screenshot 2024-03-12 at 17 56 39

Expected Behavior

should work

Operating System

Mac

Appium Inspector Version

App Version: 2024.2.2 Electron: 13.6.9 Node.js: 14.16.0

Appium Version

2.4.1

Further Information

Screenshot 2024-03-12 at 17 59 51

Appium Logs

I appreciate any help thank you!!

jlipps commented 6 months ago

When you open up the developer console log in the inspector (right-click -> Inspect -> console) before taking any actions, do you see any errors printed there?

KazuCocoa commented 6 months ago

The primary reason was maybe:

2024-03-12 18:04:32:851 - [XCUITestDriver@3015 (2b18ed6c)] Calling AppiumDriver.getTimeouts() with args: ["2b18ed6c-f38e-4465-bbda-075dfb60ec25"]
2024-03-12 18:04:32:851 - [XCUITestDriver@3015 (2b18ed6c)] Executing command 'getTimeouts'
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)] AxiosError: timeout of 240000ms exceeded
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at RedirectableRequest.handleRequestTimeout (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/axios/lib/adapters/http.js:647:16)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at RedirectableRequest.emit (node:events:518:28)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at Timeout.<anonymous> (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/follow-redirects/index.js:210:12)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at listOnTimeout (node:internal/timers:573:17)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at processTimers (node:internal/timers:514:7)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at Axios.request (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/axios/lib/core/Axios.js:45:41)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at runNextTicks (node:internal/process/task_queues:60:5)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at listOnTimeout (node:internal/timers:540:9)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at processTimers (node:internal/timers:514:7)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at JWProxy.request (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:100:14)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at JWProxy.proxy (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:234:39)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at ProtocolConverter.convertAndProxy (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/protocol-converter.js:266:12)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at JWProxy.proxyCommand (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:336:12)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at JWProxy.command (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:350:32)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.proxyCommand (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/proxy-helper.js:109:35)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.mobileGetSource (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/source.js:50:35)
2024-03-12 18:06:33:538 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.getPageSource (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/source.js:24:9)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)] Encountered internal error running command: UnknownError: An unknown server-side error occurred while processing the command. Original error: Could not proxy command to the remote server. Original error: timeout of 240000ms exceeded
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at JWProxy.command (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/node_modules/@appium/base-driver/lib/jsonwp-proxy/proxy.js:355:13)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at runNextTicks (node:internal/process/task_queues:60:5)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at listOnTimeout (node:internal/timers:540:9)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at processTimers (node:internal/timers:514:7)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.proxyCommand (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/proxy-helper.js:109:35)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.mobileGetSource (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/source.js:50:35)
2024-03-12 18:06:33:540 - [XCUITestDriver@3015 (2b18ed6c)]     at XCUITestDriver.getPageSource (/Users/theo.king/code/guacamole/testing/app-at/node_modules/appium-xcuitest-driver/lib/commands/source.js:24:9)
2024-03-12 18:06:33:540 - [HTTP] <-- GET /session/2b18ed6c-f38e-4465-bbda-075dfb60ec25/source 500 240052 ms - 1225
2024-03-12 18:06:33:540 - [HTTP]

so the get page source took longer time, and responded 500

tking16 commented 6 months ago

When you open up the developer console log in the inspector (right-click -> Inspect -> console) before taking any actions, do you see any errors printed there?

If you mean just after starting the session, then it's:

Download the React DevTools for a better development experience: https://reactjs.org/link/react-devtoolsYou might need to use a local HTTP server (instead of file://): https://reactjs.org/link/react-devtools-faq
electron/js2c/renderer_init.js:13 (electron) The remote module is deprecated. Use https://github.com/electron/remote instead.
log @ electron/js2c/renderer_init.js:13
internal/worker.js:82 [Deprecation] SharedArrayBuffer will require cross-origin isolation as of M92, around July 2021. See https://developer.chrome.com/blog/enabling-shared-array-buffer/ for more details.
(anonymous) @ internal/worker.js:82
/Applications/Appium Inspector.app/Contents/Resources/app.asar/node_modules/antd/lib/index.js:477 You are using a whole package of antd, please use https://www.npmjs.com/package/babel-plugin-import to reduce app bundle size.
(anonymous) @ /Applications/Appium Inspector.app/Contents/Resources/app.asar/node_modules/antd/lib/index.js:477
Session.js:947 Ignoring error in getting list of active sessions: AxiosError: Network Error
(anonymous) @ Session.js:947
0.0.0.0:4723/sessions:1 Failed to load resource: net::ERR_CONNECTION_REFUSED
0.0.0.0:4723/session:1 Failed to load resource: net::ERR_CONNECTION_REFUSED
node.js:100 2024-03-13T09:25:03.289Z ERROR webdriver: TypeError: Failed to fetch
(anonymous) @ node.js:100
Session.js:179 Could not connect to Appium server URL 'http://0.0.0.0:4723/'. Please check if the server is running and the URL is correct (valid URLs can be found at the start of the Appium server log). If you are using the Inspector's browser version, ensure the server has been started with '--allow-cors'.
Ie @ Session.js:179
Inspector.js:793 Calling client method with params:
Inspector.js:794 Object
appium-client.js:75 Handling client method request with method 'getPageSource' and args []
Inspector.js:733 Pinging Appium server to keep session active
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b/timeouts:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:28:25.573Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
Inspector.js:733 Pinging Appium server to keep session active
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b/timeouts:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:28:44.397Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
Inspector.js:733 Pinging Appium server to keep session active
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b/timeouts:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:29:05.007Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
Inspector.js:733 Pinging Appium server to keep session active
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b/timeouts:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:29:24.667Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
Inspector.js:733 Pinging Appium server to keep session active
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b/timeouts:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:29:41.516Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
(anonymous) @ loglevel-plugin-prefix.js:106
retry @ index.js:129
_request @ index.js:195
Inspector.js:793 Calling client method with params:
Inspector.js:794 Object
0.0.0.0:4723/session/c488b3bd-128c-4f45-a53f-8dee0bb8a50b:1 Failed to load resource: the server responded with a status of 404 (Not Found)
node.js:100 2024-03-13T09:29:49.300Z ERROR webdriver: Request failed with status 404 due to invalid session id: A session is either terminated or not started
(anonymous) @ node.js:100
Inspector.js:793 Calling client method with params:
Inspector.js:794 Object
appium-client.js:75 Handling client method request with method 'getPageSource' and args []
3Inspector.js:733 Pinging Appium server to keep session active
tking16 commented 6 months ago

@jlipps image format if it's easier to read Screenshot 2024-03-13 at 09 32 09

eglitise commented 6 months ago

Does it change anything if you remove the manually specifiedRemote Host value of 0.0.0.0?

tking16 commented 6 months ago

@eglitise That works a bit better, the app isn't crashing anymore. But when I navigate from the initial page and refresh the inspector the screenshot won't refresh and Appium give an error:

2024-03-13 11:17:12:042 - [AppiumDriver@cf60] Encountered internal error running command: NoSuchDriverError: A session is either terminated or not started
2024-03-13 11:17:12:042 - [AppiumDriver@cf60]     at asyncHandler (/Users/theo.king/code/guacamole/testing/app-at/node_modules/@appium/base-driver/lib/protocol/protocol.js:315:15)
2024-03-13 11:17:12:042 - [AppiumDriver@cf60]     at /Users/theo.king/code/guacamole/testing/app-at/node_modules/@appium/base-driver/lib/protocol/protocol.js:518:15
2024-03-13 11:17:12:042 - [AppiumDriver@cf60]     at Layer.handle [as handle_request] (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/layer.js:95:5)
2024-03-13 11:17:12:042 - [AppiumDriver@cf60]     at next (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/route.js:144:13)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Route.dispatch (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/route.js:114:3)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Layer.handle [as handle_request] (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/layer.js:95:5)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at /Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:284:15
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at param (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:365:14)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at param (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:376:14)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Function.process_params (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:421:3)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at next (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:280:10)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at logger (/Users/theo.king/code/guacamole/testing/app-at/node_modules/morgan/index.js:144:5)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Layer.handle [as handle_request] (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/layer.js:95:5)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at trim_prefix (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:328:13)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at /Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:286:9
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Function.process_params (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:346:12)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at next (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:280:10)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at jsonParser (/Users/theo.king/code/guacamole/testing/app-at/node_modules/body-parser/lib/types/json.js:113:7)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Layer.handle [as handle_request] (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/layer.js:95:5)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at trim_prefix (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:328:13)
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at /Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:286:9
2024-03-13 11:17:12:043 - [AppiumDriver@cf60]     at Function.process_params (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:346:12)
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at next (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:280:10)
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at Layer.handle [as handle_request] (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/layer.js:91:12)
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at trim_prefix (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:328:13)
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at /Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:286:9
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at Function.process_params (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:346:12)
2024-03-13 11:17:12:044 - [AppiumDriver@cf60]     at next (/Users/theo.king/code/guacamole/testing/app-at/node_modules/express/lib/router/index.js:280:10)
2024-03-13 11:17:12:045 - [HTTP] <-- GET /session/72d0d6cb-6c0f-41b3-acf6-3bc4c963f43c/timeouts 404 4

The visible difference I see is that after removing the Remote Host, the app is now initially loading the same page that it would load if you were to install manually. The app loads the consent panel first for some reason when the remote host is there (will post a picture of what that looks like), which I theorise is crashing the app when it tries to page_source. That page is only supposed to load after navigating from the initial page, if that makes sense.

Screenshot_2024-02-13_at_9_40_23 AM

eglitise commented 6 months ago

I guess the behavior for 0.0.0.0 may not be fully defined. The Appium server startup message lists the valid URLs that can be used to connect to it, and 0.0.0.0 is not among them, so it is best to keep the placeholder value of 127.0.0.1.

Still, this doesn't mean that the session should get terminated on its own like in your log.

tking16 commented 6 months ago
  • Does the error still appear if navigating from the initial page using another Appium client?

Do you mean like if I try to run the test rather than the inspector? It used to crash but not anymore, I think after updating the client. Please find the full logs below

https://gist.github.com/tking16/fd83025b76fd2a5b3838553c7d0c5a3e

eglitise commented 6 months ago

WDA seems to be taking quite a while to start up. Can you perhaps share the log of a test run for comparison? (at least up to the moment where the session termination happens in the Inspector)

tking16 commented 6 months ago

WDA seems to be taking quite a while to start up

This has always been a problem for as long as I can remember, it happens if the simulator has freshly started up. You won't see in the attached test log as I re-ran it a 2nd time. I don't think it's related to this issue though, probably because I don't have usePrebuiltWDA set 🤷🏾‍♂️ testLog.log

eglitise commented 6 months ago

One clear difference between both logs is the value of the appium:newCommandTimeout capability. In fact I missed this in the first log - it was also the reason why the session was terminated: Ending session, cause was 'New Command Timeout of 10 seconds expired. Try customizing the timeout using the 'newCommandTimeout' desired capability' In the second log you have set this value to 9999, which may be the reason why the test runs fine. Try launching the Inspector session with this same value.

tking16 commented 6 months ago

Thanks @eglitise a QA on my team just verified that setting newCommandTimeout fixed the issue 🙌🏾, I've had similar timeouts trying to use Selenium Grid, that might be the issue for that too 🤔

jlipps commented 6 months ago

Pretty sure that unless you set it otherwise the inspector uses an infinite new command timeout