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

[AnilPatidar]

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

gestures@4.0.0 [installed (npm)]
element-wait@3.0.2 [installed (npm)]
execute-driver@3.0.35 [installed (npm)]
images@3.0.19 [installed (npm)]
device-farm@9.4.3 [installed (npm)]
appium-interceptor@1.0.0-beta.12 [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]

@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.

[sudharsan-selvaraj]

@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.

[AnilPatidar]

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