Client TCP proxy buffer overflow when GET request with response content-type is multipart/x-mixed-replace

[Pixcell]

Hey guys :) We are encountering an issue with tcp proxy.

This is the request: (I have removed private informations such as IP/hosts, etc)

GENERAL:
Request Method: GET
Status Code: 200 OK
Referrer Policy: no-referrer-when-downgrade

RESPONSE HEADERS:
connection: close
content-type: multipart/x-mixed-replace; boundary=frame
date: Tue, 18 Aug 2020 23:08:56 GMT
server: Werkzeug/1.0.1 Python/3.7.3
Transfer-Encoding: chunked
X-Powered-By: Express

REQUEST HEADERS:
Accept: image/webp,image/apng,image/*,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9
Cache-Control: no-cache
Connection: keep-alive
Pragma: no-cache
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/84.0.4147.125 Safari/537.36

The proxy fails with the following logs:

2020-08-18T23:10:32.951Z iofog info *** New Mappings:  ["amqp:D3myVDqn9QDxWyth6zytqKXrgfvW7qbf=>tcp:80"]
2020-08-18T23:10:32.953Z iofog info *** Current Config:  []
2020-08-18T23:10:32.966Z iofog info *** To Delete:  []
2020-08-18T23:10:32.966Z iofog info *** To Add:  ["amqp:D3myVDqn9QDxWyth6zytqKXrgfvW7qbf=>tcp:80"]
2020-08-18T23:10:32.967Z iofog info *** Creating amqp:D3myVDqn9QDxWyth6zytqKXrgfvW7qbf=>tcp:80
[Tue Aug 18 2020 23:10:32] [LOG]   Proxying amqp:D3myVDqn9QDxWyth6zytqKXrgfvW7qbf=>tcp:80
2020-08-18T23:10:32.974Z iofog info Created AMQP to TCP bridge D3myVDqn9QDxWyth6zytqKXrgfvW7qbf => localhost:80
2020-08-18T23:10:33.247Z iofog info [raspberrypi_amqp_D3myVDqn9QDxWyth6zytqKXrgfvW7qbf_to_tcp_localhost_80] created connection scoped link route
2020-08-18T23:11:20.938Z iofog info [raspberrypi_amqp_D3myVDqn9QDxWyth6zytqKXrgfvW7qbf_to_tcp_localhost_80] receiver attached
2020-08-18T23:11:20.949Z iofog info [raspberrypi_amqp_D3myVDqn9QDxWyth6zytqKXrgfvW7qbf_to_tcp_localhost_80] receiver attached
2020-08-18T23:11:20.953Z iofog info [raspberrypi_amqp_D3myVDqn9QDxWyth6zytqKXrgfvW7qbf_to_tcp_localhost_80] socket connected to localhost:80
2020-08-18T23:11:20.955Z iofog info server tunnel created for socket 172.16.0.4:50344@undefined, amqp:/_topo/0/default-router/temp.zZYA4jR2DZ4mMWl <-> D3myVDqn9QDxWyth6zytqKXrgfvW7qbf
2020-08-18T23:11:20.956Z iofog info tcp egress connection open; metrics not enabled
2020-08-18T23:11:20.967Z iofog info [raspberrypi_amqp_D3myVDqn9QDxWyth6zytqKXrgfvW7qbf_to_tcp_localhost_80] socket connected to localhost:80
2020-08-18T23:11:20.968Z iofog info server tunnel created for socket 172.16.0.4:50342@undefined, amqp:/_topo/0/default-router/temp.oh9S2ofnISuqtFn <-> D3myVDqn9QDxWyth6zytqKXrgfvW7qbf
2020-08-18T23:11:20.968Z iofog info tcp egress connection open; metrics not enabled
[Tue Aug 18 2020 23:11:35] [ERROR] Tue, 18 Aug 2020 23:11:35 GMT Exception: circular buffer overflow: head=549 tail=549 size=2048 capacity=2048
[Tue Aug 18 2020 23:11:35] [ERROR] Error: circular buffer overflow: head=549 tail=549 size=2048 capacity=2048
    at CircularBuffer.push (/opt/app-root/node_modules/rhea/lib/session.js:56:15)
    at Outgoing.send (/opt/app-root/node_modules/rhea/lib/session.js:172:21)
    at Session.send (/opt/app-root/node_modules/rhea/lib/session.js:621:27)
    at Sender.send (/opt/app-root/node_modules/rhea/lib/link.js:334:33)
    at Server.on_socket_data (/opt/app-root/lib/tunnel.js:229:17)
    at Socket.emit (events.js:314:20)
    at addChunk (_stream_readable.js:304:12)
    at readableAddChunk (_stream_readable.js:280:9)
    at Socket.Readable.push (_stream_readable.js:219:10)
    at TCP.onStreamRead (internal/stream_base_commons.js:188:23)

This only seems to happens when the response content-type is multipart/x-mixed-replace. Which is meant to be a never ending response, "streaming" content

Thank you for your help

[grs]

Are you able to get the output from running qdstat -l against the routers when this occurs? (I think I know the fix and the issue with the proxy failure, but want to understand the root cause a little better).

[Pixcell]

The router are running as docker containers. Do you want this command ran inside the container, or on the host ?

[Pixcell]

Turns out qdstat results in command not found. Both on the host and in the container. How can I install it ?

Here is the Dockerfile used to generate the image: https://github.com/eclipse-iofog/skupper-proxy/blob/master/Dockerfile

(We have forked the repo)

[grs]

qdstat is in the router container (not the proxy) and should be run against the router. I.e you should be able to docker exec against the router container and run that command.

[Pixcell]

Sorry for the delay @grs . Seems like qdstat is not found in the router either

84061120dc74        iofog/router-arm:2.0.0                           "/qpid-dispatch/rout…"   4 days ago          Up 4 days           0.0.0.0:5672->5672/tcp   iofog_f4Y9LVqWpF43kn8WxTWZXpGHfYGpMXmL

pi@raspberrypi:~ $ sudo docker exec -it 84061120dc74 qdstat -l
OCI runtime exec failed: exec failed: container_linux.go:349: starting container process caused "exec: \"qdstat\": executable file not found in $PATH": unknown

[grs]

I've struggled to get a reliable reproducer for this issue. In the end I resorted to artificially triggering it. I have now committed what I believe to be a fix: https://github.com/skupperproject/skupper-proxy/commit/25c330aaf088822ea476ed07e088fd4317ba5a85.

Could you try that out in your image and see if it fixes things for you?

The issue (I believe) is that data from tcp arrives faster than the messages are settled. The fix will throttle the reading of tcp data if and when needed to avoid the error.