cloudamqp
Upstream closed connection: FRAME_ERROR
We are using amqproxy (0.7.0) to proxy connections from PHP (short living web and long living cli scripts) to rabbitmq instances (3.9.11).
It works mostly flawless, but sometimes on busy connections (sending 10-20k events) error occurs. Same errors on multiple independent (by network, servers, dc) environments, looks like some problem with proxing payload.
Here are errors on client (php, amqproxy localhost) side
Sep 14 09:07:51 web-1 amqproxy[5350]: Upstream closed connection: FRAME_ERROR - type 3, first 16 octets = <<"{\"client\":{\"id\":">>: {invalid_frame_end_marker,
Sep 14 09:07:51 web-1 amqproxy[5350]: 34}
Sep 14 09:07:51 web-1 amqproxy[5350]: Upstream connection closed when returned
Sep 14 09:41:11 web-1 amqproxy[5350]: Upstream closed connection: FRAME_ERROR - type 2, first 16 octets = <<0,60,0,0,0,0,0,0,0,0,0,109,16,72,2,0>>: {invalid_frame_end_marker,
Sep 14 09:41:11 web-1 amqproxy[5350]: 53}
Sep 14 09:41:11 web-1 amqproxy[5350]: Upstream connection closed when returned
Same errors I can find on RabbitMQ server side
2022-09-14 09:07:51.245109+00:00 [error] <0.13854.2346> Error on AMQP connection <0.13854.2346> (10.0.16.135:39444 -> 10.0.2.206:5672, vhost: 'xxx', user: 'xxx', state: running), channel 1:
2022-09-14 09:07:51.245109+00:00 [error] <0.13854.2346> operation none caused a connection exception frame_error: "type 3, first 16 octets = <<\"{\\\"client\\\":{\\\"id\\\":\">>: {invalid_frame_end_marker,\n 34}"
2022-09-14 09:07:54.262755+00:00 [error] <0.13854.2346> closing AMQP connection <0.13854.2346> (10.0.16.135:39444 -> 10.0.2.206:5672):
2022-09-14 09:41:11.642132+00:00 [error] <0.27415.1436> Error on AMQP connection <0.27415.1436> (10.0.16.135:45074 -> 10.0.2.206:5672, vhost: 'xxx', user: 'xxx', state: running), channel 1:
2022-09-14 09:41:11.642132+00:00 [error] <0.27415.1436> operation none caused a connection exception frame_error: "type 2, first 16 octets = <<0,60,0,0,0,0,0,0,0,0,0,109,16,72,2,0>>: {invalid_frame_end_marker,\n 53}"
2022-09-14 09:41:14.656840+00:00 [error] <0.27415.1436> closing AMQP connection <0.27415.1436> (10.0.16.135:45074 -> 10.0.2.206:5672):
2022-09-14 09:41:14.656840+00:00 [error] <0.27415.1436> fatal_frame_error
any ideas?
Thanks
Maybe fixed in https://github.com/cloudamqp/amqproxy/commit/2c1169dae54ec6257e7dc049ccb0fbecbadf52a6
I've compiled version from master, but it looks problem still exist
Sep 21 06:54:12 web-1 amqproxy[26921]: Upstream closed connection: FRAME_ERROR - type 3, first 16 octets = <<"{\"client\":{\"id\":">>: {invalid_frame_end_marker,
Sep 21 06:54:12 web-1 amqproxy[26921]: 54}
Sep 21 06:54:12 web-1 amqproxy[26921]: Upstream connection closed when returned
Sep 21 06:58:49 web-1 amqproxy[26921]: Upstream closed connection: FRAME_ERROR - type 2, first 16 octets = <<0,60,0,0,0,0,0,0,0,0,0,113,16,72,2,0>>: {invalid_frame_end_marker,
Sep 21 06:58:49 web-1 amqproxy[26921]: 47}
Sep 21 06:58:49 web-1 amqproxy[26921]: Upstream connection closed when returned
Sep 21 07:33:08 web-1 amqproxy[26921]: Upstream closed connection: FRAME_ERROR - type 3, all octets = <<0,1,0>>: {invalid_frame_end_marker,0}
Sep 21 07:33:11 web-1 amqproxy[26921]: Upstream connection closed when returned
Sep 21 07:44:29 web-1 amqproxy[26921]: Upstream closed connection: FRAME_ERROR - type 2, first 16 octets = <<0,60,0,0,0,0,0,0,0,0,0,113,16,72,2,0>>: {invalid_frame_end_marker,
Sep 21 07:44:29 web-1 amqproxy[26921]: 115}
Sep 21 07:44:32 web-1 amqproxy[26921]: Upstream connection closed when returned
I have successfully reproduced this issue with 5 concurrent producers (after ~3mln messages) - happens every time.
2022-11-05 12:55:34 +01:00: Upstream closed connection: FRAME_ERROR - type 3, all octets = <<"foobar">>: {invalid_frame_end_marker,3} 2022-11-05 12:55:34 +01:00: Upstream connection closed when returned 2022-11-05 12:55:34 +01:00: Upstream closed connection: FRAME_ERROR - type 2, first 16 octets = <<0,60,0,0,0,0,0,0,0,0,0,6,144,0,10,116>>: {invalid_frame_end_marker,
For tests I've added lock on write operation to Upstream - it solved this issue and performance was not affected.
PR is here https://github.com/cloudamqp/amqproxy/pull/91
