Repeated automatic recovery after rabbitmq restart #376
Assignees
Comments
|
Any exception on the reader loop will result in a recovery attempt because Bunny cannot make assumptions about whether its socket is still actually functional. It sounds like a Docker-specific issue but please submit a PR that helps your case. I can test it some more. |
|
OK, this introduces no regressions and makes sense to me. #377 is merged and will be in |
take-five
added a commit
to salemove/freddy
that referenced
this issue
Sep 26, 2016
This resolves an issue with automatic recovery from network failures in docker containers. See ruby-amqp/bunny#376
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
With automatic recovery turned on and heartbeat set to 30 seconds, we noticed that after rabbitmq was killed and restarted, Bunny 2.2.2 would detect and recover from the network failure, and then repeatedly detect and recover from more "network failures" over and over again every ~60 seconds.
We can reproduce the issue from our ubuntu docker container, talking to rabbitmq 3.5.4 running in another docker container, by running
Bunny::new(automatic_recovery: true, heartbeat: 30, log_level: :debug, host: 'mq').start, then kill and restart the rabbitmq container:From Bunny:
After rabbitmq restart, Bunny was able to recover:
But after a few heartbeat, it "detects" another "network failure" again even though rabbit and the network were fine:
The pattern repeated itself, about once every minute or so
Based on the little we know about Bunny, it seems like during the first recovery attempt after the reader loop detects the failure, it tried to recover from the failure and created 2 new transports and 2 new reader loops.
The first reader loop was created thru here (line number may be off due to extra debug logging):
After the first error in read_fully was caught and handled, it seems like it continued on to
decode_headerwhich also failed and triggered a second call tohandle_network_failurefrom here:It seems like now there are 2 reader loop threads with different transports are running concurrently while there is only one heartbeat sender sending heartbeats over only one of the transport. After ~66 seconds (2.2 x heartbeat), the reader loop thread that didn't have a heartbeat timed out.
That kicked off another round of network failure recovery, creating a new transport, creating a new reader loop, and restarting the heartbeat sender on the new transport. Now once again we have 2 reader loops with 2 transports, and only one of them has a heartbeat. The same pattern repeated itself again 66 seconds later and the one thread that didn't have a heartbeat timed out.
We were able to fix the symptom by adding this line
@reader_loop.stop if @reader_looptohandle_network_failure()to here, which will flag the reader_loop to stop before it tries to create a new one.I suspect adding that line here may work too.
BTW, we were not able to reproduce the same symptom on OS X, not sure why.
The text was updated successfully, but these errors were encountered: