[Koha-bugs] [Bug 32481] Rabbit times out when too many jobs are queued and the response takes too long

[bugzilla-daemon at bugs.koha-community.org]

https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32481

--- Comment #19 from Nick Clemens <nick at bywatersolutions.com> ---
(In reply to Jonathan Druart from comment #18)
> I think I recreate the problem this way:
> 
> % more /etc/rabbitmq/rabbitmq.conf
> consumer_timeout = 15000
> 
> Add a sleep 10 in Koha::BackgroundJob::BatchUpdateItem->process
> 
> Then enqueue several batch item mod jobs.
> 
> However:
> 1. I don't see jobs stuck in "new" (without the patch)
> 
> 2. I am seeing the following in the rabbitmq logs, with and without the patch
> 
> 2023-01-04 11:01:03.041 [warning] <0.2774.0> Consumer
> Q_/queue/koha_kohadev-long_tasks on channel 1 has timed out waiting on
> consumer acknowledgement. Timeout used: 15000 ms                            
> 
> 2023-01-04 11:01:03.041 [error] <0.2774.0> Channel error on connection
> <0.2764.0> (127.0.0.1:39578 -> 127.0.0.1:61613, vhost: '/', user: 'guest'),
> channel 1:                                                        
> operation none caused a channel exception precondition_failed: consumer ack
> timed out on channel 1                                                      
> 
> 2023-01-04 11:01:03.042 [error] <0.2758.0> STOMP error frame sent:          
> 
> Message: precondition_failed
> Detail: "PRECONDITION_FAILED - consumer ack timed out on channel 1\n"
> Server private detail: none
> 2023-01-04 11:01:03.042 [info] <0.2758.0> closing STOMP connection
> <0.2758.0> (127.0.0.1:39578 -> 127.0.0.1:61613)

I played with this a bunch, and things seem to sometimes recover and sometimes
not

Setting rabbitmq.conf with:
consumer_timeout = 10000

Adding "sleep 1;" in the Koha/BackgroundJob/UpdateElasticIndex.pm

sudo koha-mysql kohadev
DELETE FROM biblio WHERE biblionumber=269;
DELETE FROM biblio WHERE biblionumber=72;

Set SearchEngine syspref to 'Elastic'

perl misc/maintenance/touch_all_biblios.pl

With or without patch, I get errors like:
2023-01-04 16:49:40.689 [warning] <0.7712.0> Consumer
Q_/queue/koha_kohadev-default on channel 1 has timed out waiting on consumer
acknowledgement. Timeout used: 10000 ms
2023-01-04 16:49:40.692 [error] <0.7712.0> Channel error on connection
<0.7703.0> (127.0.0.1:60178 -> 127.0.0.1:61613, vhost: '/', user: 'guest'),
channel 1:
operation none caused a channel exception precondition_failed: consumer ack
timed out on channel 1
2023-01-04 16:49:40.692 [error] <0.7700.0> STOMP error frame sent:
Message: precondition_failed
Detail: "PRECONDITION_FAILED - consumer ack timed out on channel 1\n"
Server private detail: none
2023-01-04 16:49:40.693 [info] <0.7700.0> closing STOMP connection <0.7700.0>
(127.0.0.1:60178 -> 127.0.0.1:61613)
2023-01-04 16:49:41.224 [info] <0.14720.0> accepting STOMP connection
<0.14720.0> (127.0.0.1:60376 -> 127.0.0.1:61613)
2023-01-04 16:49:41.235 [error] <0.14732.0> Channel error on connection
<0.14723.0> (127.0.0.1:60376 -> 127.0.0.1:61613, vhost: '/', user: 'guest'),
channel 1:
operation basic.ack caused a channel exception precondition_failed: unknown
delivery tag 245
2023-01-04 16:49:41.239 [error] <0.14720.0> STOMP error frame sent:
Message: precondition_failed
Detail: "PRECONDITION_FAILED - unknown delivery tag 245\n"
Server private detail: none
2023-01-04 16:49:41.239 [info] <0.14720.0> closing STOMP connection <0.14720.0>
(127.0.0.1:60376 -> 127.0.0.1:61613)
2023-01-04 16:49:42.477 [info] <0.14736.0> accepting STOMP connection
<0.14736.0> (127.0.0.1:60388 -> 127.0.0.1:61613)


And varied number of jobs that remain in new

-- 
You are receiving this mail because:
You are watching all bug changes.