Continuation timeout issue

[thomasLeclaire]

Hello!
I'm using hutch (last version of gem), but opening discussion on bunny like exception is on bunny side.
Some "standard" code to publish and no particular config :
Hutch.connect Hutch.publish(routing_key, params)
We added recently Hutch::Config.set(:force_publisher_confirms, true) in order to be able to catch error and manage some retry.

So my issue is we have some message "lost" between my publisher and the rabbitserver.
My rabbit is a basic 3 nodes install running in a GKE cluster. My app also running same cluster.
Adding Debug logs everywhere, I have no info on rabbit side. I see the normal user connection and no other messages (no error, no disconnection,..).
on my app side : I get an exception triggered by bunny : Timeout::Error: Timeout::Error in /home/effilab/vendor/bundle/ruby/3.1.0/gems/bunny-2.19.0/lib/bunny/concurrent/continuation_queue.rb:39:in `block in poll'

I checked the related code in bunny but i'm not sure to understand what is this continuation_queue .

in hutch debug logs, no specific info :

in bunny logs, I can't really tell if it' normal or not. (I consider strange the quantity of "Sending a heartbeat, last activity time: " however, see attachement.
bunny.log

Even if everything internal to the cluster i also checked network/dns/k8s stuffs but nothing found.

Can you help me to understand what can be the issue? or what can I do to find it?

many thanks for the help

[thomasLeclaire]

Hi again,
I installed some tcp sniffing to check what go out from my pod during a timeout.

in hutch logs : I can see :

publishing message '{"product_ids":[223],"timestamp":"1665741863"}' to sync_products.fsa
publishing message '{"product_ids":[223],"timestamp":"1665741863"}' to sync_products.rtb
publishing message '{"product_ids":[223],"timestamp":"1665741878"}' to sync_products.rtb

as we can see the first sent on fsa queue was ok. but the first sent on rtb queue has been missed, therefore our auto retry which resend it 15sec after (the time of continutation timeout).
here the wireshark captures :

From what I see, it sounds like messages are correctly sent and acked but I'm really not rabbitmq or wireshark expert, so I still don't understand what can be my issue.. :'(

I'm however surprised to see the same seq number in both "initial" messages.

[michaelklishin]

This timeout is for receiving responses. basic.publish and basic.ack do not have responses define in the protocol.

My best guess is that you may be sharing a channel between threads and this is a concurrency hazard.

[thomasLeclaire]

ok it sounds to be the case yes.. Strangely we already use a same code without getting the issue but sounds like we were just lucky or we miss the lost!
Anyway, yes the sidekiq instance which manage this publication was working on 5 threads, and putting it in a mono-thread one, we don't have anymore any issue.

sorry for the noise!

[michaelklishin]

Sidekiq controlling your concurrency. A classic ;)