fread slow when consuming a message

[frankvanhest]

Good morning,

For some reason the line $s = @fread($this->stream, $this->frameMax); in AbstractClient::read() just waits for data for some messages being consumed. Bunny is used in a project which communicates with a DNS Management Service by RabbitMQ using the RPC pattern. For some request (retrieving a DNS zone) the consumer from the reply queue waits for a long (10s for example). First I thought that the consumer in the DNS Management was slow, but this puts the reply message onto the reply queue within 25ms. When I look what is going one with the reply queue in RabbitMQ admin panel, I see that the message is consumed, but the state is unacked. The strange thing is, that this only happens for a few zones at a specific environment. Zone A on production is slow, but the same zone on acceptance is fast. The only difference is that the environments are on a different server, but with the same software and configuration. The both use the same RabbitMQ server. My question is, what can I do to see why the process waits at the fread call? Is there a way to see in RabbitMQ if the message is consumed and the data is send to it?

Hopefully you can give me some pointers. I would appreciate that.

Thank you in advance.

Cheers,

Frank

[frankvanhest]

After some further testing, the delay only happens when the rabbitmq server is not running on localhost, the message is larger than 128kb and the connection to rabbitmq is with SSL. The delay seems somehow to be related to the heartbeat interval. For example if the heartbeat interval is set to 30 seconds, the delay is 15 seconds. When set to 10 seconds, the delay is 5 seconds.

Hopefully you can find the time to give me some pointers.

[WyriHaximus]

One way of looking into those things would be to add metrics, or some other way of observability. Maybe through middleware.

But one of the things I want to change is to fully rely on react/socket and react/stream for I/O instead of using our own. That on it's own might already solve this as we tackled lots of tiny bugs like this there.

[frankvanhest]

Thank you for your reply. I see that my initial message wasn't clear. The slow fread occurs within Bunny itself. I'm not using my own implementation to consume from the queue.
Here is the exact line in Bunny. https://github.com/jakubkulhan/bunny/blob/e03224f076a21fa386b1da1b29381c3e0acab603/src/Bunny/AbstractClient.php#L298

I'll try to create a small project to reproduce this. Is it perhaps possible for you to look into this?

[WyriHaximus]

I'll try to create a small project to reproduce this. Is it perhaps possible for you to look into this?

Currently spending time to work out/on some issues/updates with/for Bunny, this will be one of them.

[frankvanhest]

Great thanks! I appreciate you taking the time! I've got a POC which shows the delay when using RabbitMQ on an external server with SSL. Update the connection options in consumer.php and rpc-publisher.php to you own environment. After a composer install ofcourse. Run the script consumer.php with the number of bytes as the first argument. In another terminal run the script rpc-publisher.php. This script will show the time it took to finish reading the message. I found that the delay occurs if the number of bytes is set to at least 12214. When you connect to RabbitMQ without SSL, then there is no delay. The delay seems to be related to the number of seconds for the heartbeat in roc-publisher.php. When this is set for example to 30 seconds, the delay is 14.9 seconds. If it is set to 10 seconds, the delay is 4.9. I've included a small video which shows this behaviour. The behaviour is the same for from PHP 7.1 and to 8.0.

Hopefully you can find something.

slow-fread.zip