appium-interceptor-plugin icon indicating copy to clipboard operation
appium-interceptor-plugin copied to clipboard

Error: Cannot write headers after they are sent to the client : Blocker issue for Appium scripts with the interceptor plugin

Open AnilPatidar opened this issue 1 year ago • 3 comments
trafficstars

Background : My script has added the mock and clicked on an element, app triggered an API call which successfully mocked by the plugin,but very next command to click on next failed which is fine but socket also got hanged up . and resulted in killing running Appium Server , it literally killed the running Appium Server

Listing available plugins

[email protected] [installed (npm)] [email protected] [installed (npm)] [email protected] [installed (npm)] [email protected] [installed (npm)] [email protected] [installed (npm)] [email protected] [installed (linked from .)] relaxed-caps [not installed] universal-xml [not installed]

Could see error - uncaughtException: Cannot write headers after they are sent to the client, at at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/src/utils/proxy.ts:102:33

Appium Logs: 2024-11-16 19:47:54:456 - [177416a0][AppiumDriver@5821] Clearing new command timeout pre-emptively since plugin(s) will handle this command 2024-11-16 19:47:54:456 - [177416a0][AppiumDriver@5821] Plugins which can handle cmd 'click': device-farm 2024-11-16 19:47:54:456 - [177416a0][AppiumDriver@5821] Plugin device-farm is now handling cmd 'click' 2024-11-16 19:47:54:456 - [177416a0][AppiumDriver@5821] Executing default handling behavior for command 'click' 2024-11-16 19:47:54:456 - [177416a0][AndroidUiautomator2Driver@e48d] Matched '/element/00000000-0000-0075-ffff-ffff00000050/click' to command name 'click' 2024-11-16 19:47:54:457 - [177416a0][AndroidUiautomator2Driver@e48d] Proxying [POST /element/00000000-0000-0075-ffff-ffff00000050/click] to [POST http://127.0.0.1:61086/session/e8bd75d6-a226-4060-9f4f-9733f3f32220/element/00000000-0000-0075-ffff-ffff00000050/click] with body: {"element":"00000000-0000-0075-ffff-ffff00000050"} 2024-11-16 19:47:54:457 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Updating lastCmdExecutedAt for device RZ8TA114VMF in session 177416a0-4969-42b9-856d-906394be3d70 2024-11-16 19:47:54:590 - [177416a0][AndroidUiautomator2Driver@e48d] Got response with status 200: {"sessionId":"e8bd75d6-a226-4060-9f4f-9733f3f32220","value":null} 2024-11-16 19:47:54:590 - [177416a0][AndroidUiautomator2Driver@e48d] Responding to client with driver.click() result: null 2024-11-16 19:47:54:591 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Intercepted response for session 177416a0-4969-42b9-856d-906394be3d70 with method click {} 177416a0-4969-42b9-856d-906394be3d70 2024-11-16 19:47:54:591 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Saving log entry for session 177416a0-4969-42b9-856d-906394be3d70 with eventId undefined 2024-11-16 19:47:54:595 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Successfully saved log entry for 177416a0-4969-42b9-856d-906394be3d70, commandName: click 2024-11-16 19:47:54:595 - [177416a0][HTTP] <-- POST /wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element/00000000-0000-0075-ffff-ffff00000050/click 200 141 ms - 14 creating SNI context for docker.xyz.com 2024-11-16 19:47:55:092 - [364cc1c2][AndroidUiautomator2Driver@e749] Matched '/element' to command name 'findElement' 2024-11-16 19:47:55:092 - [364cc1c2][AndroidUiautomator2Driver@e749] Proxying [POST /element] to [POST http://127.0.0.1:60804/session/18e9b142-f746-4b8e-a0c1-4350ebe9a30b/element] with body: {"strategy":"accessibility id","selector":"cricket-home","context":"","multiple":false} 2024-11-16 19:47:55:341 - [364cc1c2][AndroidUiautomator2Driver@e749] Got response with status 404: {"sessionId":"18e9b142-f746-4b8e-a0c1-4350ebe9a30b","value":{"error":"no such element","message":"An element could not be located on the page using the given search parameters","stacktrace":"io.appium.uiautomator2.common.exceptions.ElementNotFoundException: An element could not be located on the page using the given search parameters\n\tat io.appium.uiautomator2.handler.FindElement.safeHandle(FindElement.java:63)\n\tat io.appium.uiautomator2.handler.request.SafeRequestHandler.handle(SafeRequestHandler.java:59)\n\tat io.appium.uiautomator2.server.AppiumServlet.handleRequest(AppiumServlet.java:259)\n\tat io.appium.uiautomator2.server.AppiumServlet.handleHttpRequest(AppiumServlet.java:253)\n\tat io.appium.uiautomator2.http.ServerHandler.channelRead(ServerHandler.java:77)\n\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:366)\n\tat io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:352)\n\tat io.netty.chann... 2024-11-16 19:47:55:343 - [364cc1c2][W3C] Matched W3C error code 'no such element' to NoSuchElementError 2024-11-16 19:47:55:343 - [364cc1c2][AndroidUiautomator2Driver@e749] Waited for 2503 ms so far 2024-11-16 19:47:55:373 - uncaughtException: Cannot write headers after they are sent to the client Error: Cannot write headers after they are sent to the client at ServerResponse.writeHead (node:_http_server:345:11) at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/src/utils/proxy.ts:102:33 at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/proxy.ts:1384:25 at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:2589:44 at eachOfArrayLike (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:507:13) at eachOf (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:627:16) at awaitable (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:212:32) at Object.eachLimit$2 (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:2692:16) at Object.awaitable (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:212:32) at Proxy._onResponseEnd (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/proxy.ts:1382:11) at ProxyFinalResponseFilter.end (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/ProxyFinalResponseFilter.ts:40:22) at Gunzip.onend (node:internal/streams/readable:946:10) at Object.onceWrapper (node:events:633:28) at Gunzip.emit (node:events:519:28) at endReadableNT (node:internal/streams/readable:1696:12) at processTicksAndRejections (node:internal/process/task_queues:82:21) 2024-11-16 19:47:55:374 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] ****** UncaughtException ****** 2024-11-16 19:47:55:374 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Error: Error [ERR_HTTP_HEADERS_SENT]: Cannot write headers after they are sent to the client 2024-11-16 19:47:55:374 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Error: Cannot write headers after they are sent to the client at ServerResponse.writeHead (node:_http_server:345:11) at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/src/utils/proxy.ts:102:33 at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/proxy.ts:1384:25 at /Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:2589:44 at eachOfArrayLike (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:507:13) at eachOf (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:627:16) at awaitable (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:212:32) at Object.eachLimit$2 (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:2692:16) at Object.awaitable (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/async/dist/async.js:212:32) at Proxy._onResponseEnd (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/proxy.ts:1382:11) at ProxyFinalResponseFilter.end (/Users/jenkins-lab5/.appium/node_modules/appium-interceptor/node_modules/http-mitm-proxy/lib/ProxyFinalResponseFilter.ts:40:22) at Gunzip.onend (node:internal/streams/readable:946:10) at Object.onceWrapper (node:events:633:28) at Gunzip.emit (node:events:519:28) at endReadableNT (node:internal/streams/readable:1696:12) at processTicksAndRejections (node:internal/process/task_queues:82:21) 2024-11-16 19:47:55:846 - [364cc1c2][AndroidUiautomator2Driver@e749] Matched '/element' to command name 'findElement' 2024-11-16 19:47:55:854 - [364cc1c2][AndroidUiautomator2Driver@e749] Proxying [POST /element] to [POST http://127.0.0.1:60804/session/18e9b142-f746-4b8e-a0c1-4350ebe9a30b/element] with body: {"strategy":"accessibility id","selector":"cricket-home","context":"","multiple":false} 2024-11-16 19:47:57:791 - [177416a0][HTTP] --> POST /wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element {"using":"accessibility id","value":"otp_field"} 2024-11-16 19:47:57:792 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Updating lastCmdExecutedAt for device RZ8TA114VMF in session 177416a0-4969-42b9-856d-906394be3d70 2024-11-16 19:47:57:792 - [177416a0][device-farm-/Users/jenkins-lab5/.appium] Registered response interceptor for url /wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element 2024-11-16 19:47:57:793 - [177416a0][AndroidUiautomator2Driver@e48d] Calling AppiumDriver.findElement() with args: ["accessibility id","otp_field","177416a0-4969-42b9-856d-906394be3d70"]

On CI got this error :

2024-11-17 01:17:54 INFO Logger:34 - [RZ8TA114VMF] - Wait for 3 sec - Fetch OTP From DB using mobile number : 7175435015 2024-11-17 01:17:54 INFO WaitUtils:38 - [RZ8TA114VMF] - Wait for 3 sec - Fetch OTP From DB using mobile number : 7175435015 2024-11-17 01:17:57 INFO Logger:34 - [RZ8TA114VMF] - Fetched OTP from DB 2024-11-17 01:17:57 INFO FTAndroidLoginPage:38 - [RZ8TA114VMF] - Fetched OTP from DB 2024-11-17 01:17:57 INFO Logger:34 - [RZ8TA114VMF] - entering otp 2024-11-17 01:17:57 INFO FTAndroidLoginPage:38 - [RZ8TA114VMF] - entering otp [38;5;157m[177416a0][0m[38;5;86m[HTTP][0m [37m-->[39m [37mPOST[39m [37m/wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element[39m {"using":"accessibility id","value":"otp_field"} [38;5;157m[177416a0][0m[38;5;-140m[device-farm-/home/jenkins/.appium][0m Updating lastCmdExecutedAt for device 50f4c160-e349-4426-b263-ca319caabdb9 in session 177416a0-4969-42b9-856d-906394be3d70 [38;5;157m[177416a0][0m[38;5;-140m[device-farm-/home/jenkins/.appium][0m proxy handler error: socket hang up data: undefined [38;5;86m[HTTP][0m <-- POST /wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element - - ms - - [38;5;157m[177416a0][0m[38;5;86m[HTTP][0m [37m-->[39m [37mPOST[39m [37m/wd/hub/session/177416a0-4969-42b9-856d-906394be3d70/element[39m {"using":"accessibility id","value":"otp_field"} [38;5;157m[177416a0][0m[38;5;-140m[device-farm-/home/jenkins/.appium][0m Updating lastCmdExecutedAt for device 50f4c160-e349-4426-b263-ca319caabdb9 in session 177416a0-4969-42b9-856d-906394be3d70 [38;5;157m[177416a0][0m[38;5;-140m[device-farm-/home/jenkins/.appium][0m proxy handler error: connect ECONNREFUSED 192.168.100.39:4723 data: undefined

AnilPatidar avatar Nov 16 '24 20:11 AnilPatidar

@saikrishna321 @sudharsan-selvaraj it is still present, even after adding try catch , it is stopping to mock the api , just that, session is not being terminated because added try catch in the plugin.

AnilPatidar avatar Nov 18 '24 12:11 AnilPatidar

@AnilPatidar This issue could happen if the client's request is aborted or killed due to a timeout, and we still try to write the body to an empty response stream.

We need to add a check here to see if ctx.proxyToClientResponse is still open and no response has been sent back to the client. Let me know if you could pick it up. If not, I will push a fix.

sudharsan-selvaraj avatar Nov 18 '24 13:11 sudharsan-selvaraj

@sudharsan-selvaraj please go ahead. I tried but didn't work the fix, thanks alot.

AnilPatidar avatar Nov 19 '24 20:11 AnilPatidar