go-rabbitmq icon indicating copy to clipboard operation
go-rabbitmq copied to clipboard

only reconnecting some consumers

Open MaxBreida opened this issue 11 months ago • 1 comments

Hey, we encounter some problems with the reconnection of consumers in our services. It seems that only some of them are being recovered, sometimes even none at all.

Initializing environment variables...
Initializing queues...
2023-07-25T13:40:02+02:00 ??? 2023/07/25 13:40:02 gorabbit INFO: Processing messages on 1 goroutines
2023-07-25T13:40:03+02:00 ??? 2023/07/25 13:40:03 gorabbit INFO: Processing messages on 1 goroutines
2023-07-25T13:40:03+02:00 ??? 2023/07/25 13:40:03 gorabbit INFO: Processing messages on 1 goroutines
2023-07-25T13:40:03+02:00 ??? 2023/07/25 13:40:03 gorabbit INFO: Processing messages on 1 goroutines
start consuming events
Started to listen for sigkill and sigterm
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit INFO: rabbit consumer goroutine closed
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit ERROR: attempting to reconnect to amqp server after connection close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit ERROR: attempting to reconnect to amqp server after close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit ERROR: attempting to reconnect to amqp server after close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T13:46:18+02:00 ??? 2023/07/25 13:46:18 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: error closing connection while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit INFO: successful connection recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: error closing channel while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit INFO: successful publisher recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: error closing channel while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit INFO: successful consumer recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T13:46:23+02:00 ??? 2023/07/25 13:46:23 gorabbit INFO: Processing messages on 1 goroutines
recreating channel cause of error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 connection closed, reason: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 Exception (504) Reason: "channel/connection is not open"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 channel closed, reason: %vException (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit INFO: rabbit consumer goroutine closed
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit ERROR: attempting to reconnect to amqp server after connection close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit ERROR: attempting to reconnect to amqp server after close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit ERROR: attempting to reconnect to amqp server after close with error: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T14:10:16+02:00 ??? 2023/07/25 14:10:16 gorabbit INFO: waiting 5s seconds to attempt to reconnect to amqp server
2023-07-25T14:10:19+02:00 ??? 2023/07/25 14:10:19 channel recreate failed, err: Exception (504) Reason: "channel/connection is not open"
2023-07-25T14:10:19+02:00 ??? 2023/07/25 14:10:19 reconnect success
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: error closing connection while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit INFO: successful connection recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: error closing channel while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit INFO: successful consumer recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: error closing channel while reconnecting: Exception (504) Reason: "channel/connection is not open"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit WARN: successfully reconnected to amqp server
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit INFO: successful publisher recovery from: Exception (320) Reason: "CONNECTION_FORCED - broker forced connection closure with reason 'shutdown'"
2023-07-25T14:10:21+02:00 ??? 2023/07/25 14:10:21 gorabbit INFO: Processing messages on 1 goroutines
2023-07-25T14:10:22+02:00 ??? 2023/07/25 14:10:22 channel recreate success
2023-07-25T14:24:37+02:00 INF successfully handled event: xyz service=zyx <---- from one consumer
--- no further messages after that --- 

As you can see the service started with 4 consumers but only one seems to have reconnected. This seems to be a similar or even the same issue as #99. I've also checked #87 but we're already using only one consumer per queue.

Should the consumers have each their own connection (#79)? Maybe I've misunderstood something but I thought with the connectionManager and channelManager there shouln't be a need for this. Using v0.12.4

MaxBreida avatar Jul 26 '23 19:07 MaxBreida