[Bug 32393] New: background job worker explodes if JSON is incorrect
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Bug ID: 32393 Summary: background job worker explodes if JSON is incorrect Change sponsored?: --- Product: Koha Version: unspecified Hardware: All OS: All Status: ASSIGNED Severity: normal Priority: P5 - low Component: Architecture, internals, and plumbing Assignee: jonathan.druart+koha@gmail.com Reporter: jonathan.druart+koha@gmail.com QA Contact: testopia@bugs.koha-community.org If a message that is not (or incorrect) JSON is received by the worker, the script will explode. Additionally, it will restart and get the same frame, over and over again, which means no other job will be processed. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Depends on| |32394 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32394 [Bug 32394] Long tasks queue is never used -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|ASSIGNED |Needs Signoff -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #1 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 144401 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=144401&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |dcook@prosentient.com.au, | |m.de.rooy@rijksmuseum.nl, | |martin.renvoize@ptfs-europe | |.com, tomascohen@gmail.com -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32395 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |32395 See Also|https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32395 | Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32395 [Bug 32395] Why do we send jobs params to the broker -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #2 from Tomás Cohen Arazi <tomascohen@gmail.com> --- Comment on attachment 144401 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=144401 Bug 32393: Prevent invalid job to block the job queue Review of attachment 144401: --> (https://bugs.koha-community.org/bugzilla3/page.cgi?id=splinter.html&bug=32393&attachment=144401) ----------------------------------------------------------------- ::: misc/background_jobs_worker.pl @@ +104,5 @@
+ Koha::Logger->get->warn(sprintf "Job and/or frame not processed - %s", $_); + } finally { + $job->status('failed')->store if $job; + $conn->ack( { frame => $frame } ); + };
The finally block is always executed regardless of the exit status of the try block. It reads wrong to be setting the status as failed. That line belongs to the catch IMHO. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Tomás Cohen Arazi <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Failed QA -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #144401|0 |1 is obsolete| | --- Comment #3 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 144569 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=144569&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Failed QA |Needs Signoff --- Comment #4 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- I've amended the patch with the following change: - $job->status('failed')->store if $job; + $job->status('failed')->store if $job && @_; -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Tomás Cohen Arazi <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Failed QA --- Comment #5 from Tomás Cohen Arazi <tomascohen@gmail.com> --- Hi I tried this: kohadev-koha@kohadevbox:/kohadevbox/koha$ perl -MTry::Tiny -e 'try { die "Boo"; } catch { warn "catch"; } finally { warn "finally" if $@; };' catch at -e line 1. kohadev-koha@kohadevbox:/kohadevbox/koha$ perl -MTry::Tiny -e 'try { die "Boo"; } catch { warn "catch"; } finally { warn "finally" if $_; };' catch at -e line 1. In both cases it never prints "finally", so I guess the error buffer is cleared after the catch block. Do you think it would work if we just move the $job->status('failed') to the catch block? It looks cleaner too. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Failed QA |Needs Signoff --- Comment #6 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Tomás Cohen Arazi from comment #5)
Hi
I tried this:
kohadev-koha@kohadevbox:/kohadevbox/koha$ perl -MTry::Tiny -e 'try { die "Boo"; } catch { warn "catch"; } finally { warn "finally" if $@; };' catch at -e line 1. kohadev-koha@kohadevbox:/kohadevbox/koha$ perl -MTry::Tiny -e 'try { die "Boo"; } catch { warn "catch"; } finally { warn "finally" if $_; };' catch at -e line 1.
In both cases it never prints "finally", so I guess the error buffer is cleared after the catch block. Do you think it would work if we just move the $job->status('failed') to the catch block? It looks cleaner too.
It's @_ % perl -MTry::Tiny -e 'try { die "Boo"; } catch { warn "catch"; } finally { warn "finally" if @_; };' catch at -e line 1. finally at -e line 1. IMO it's better in the finally block, in case we add more stuff in catch later. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Failed QA --- Comment #7 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- There are 2 ack sent, because of the fork I guess. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32481 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #8 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145064 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145064&action=edit Bug 32393: Remove fork -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Kyle M Hall <kyle@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |kyle@bywatersolutions.com --- Comment #9 from Kyle M Hall <kyle@bywatersolutions.com> --- (In reply to Jonathan Druart from comment #8)
Created attachment 145064 [details] [review] Bug 32393: Remove fork
Just a thought; removing that fork will cause the workers memory footprint to balloon as soon as the plugins require is evaluated which obviates the bug patch where you introduce the require. I think this pushes us farther in the direction of needing to ack each request before handling the job. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #10 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- I agree that removing the fork is a bad idea.. it was implimented for the reasoning Kyle suggests I believe.. to keep the memory footprint from balooning. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Martin Renvoize <martin.renvoize@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32370 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #11 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- I left the patch here yesterday after my day work. I was working on bug 32481, and thought that this first patch was a good base to work on. So far I am only trying to make things work correctly. IMO we should not add anything new to the worker, but focus on fixing its behaviours instead.
From bug 32481 comment 22 "The best solution I found is the 2 patches from bug 32393."
I didn't want to add the patches there and add more confusion so just dropped them here. I still don't have anything good to suggest, and remove the fork is indeed a very bad idea. But fixing the worker's behaviour is a higher priority than memory footprint right now anyway. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #12 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- There's scope creep here.. the try encompasses the process_job which means it's also catching all sorts of other possible failures from each and every processor that's written. I think we should limit the scope of this bug to only catch bad JSON encoding and leave error handling for individual tasks to the tasks themselves. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #13 from Martin Renvoize <martin.renvoize@ptfs-europe.com> --- Also.. if we do want to only acknowledge on process completion, should we not do it within the forked worker? -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #14 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Martin Renvoize from comment #12)
I think we should limit the scope of this bug to only catch bad JSON encoding and leave error handling for individual tasks to the tasks themselves.
We should not trust the job and catch potential crashes IMO, to prevent a bad job to take the worker down. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #15 from David Cook <dcook@prosentient.com.au> --- We need to keep the fork, and catching all exceptions makes sense to me. You could say that the background job worker is really a background job server and servers really shouldn't go down. They should be reporting on the failures. Of course the tough part here is that the job ID is in the JSON, so if the JSON can't be decoded, there is no way to fail the job and it just stays stuck in "new" forever. I haven't been following the bad JSON bugs carefully enough though. Since we control both ends, we shouldn't be creating and transmitting bad JSON... -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #16 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Just a simple observation: + my $job_id; You are not using this variable (after all). -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #17 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- } finally { $job->status('failed')->store if $job && @_; Looks like a typo. Did you mean $@ ? And would testing that be enough or even appropriate in a finally block ? -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #18 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- (In reply to Marcel de Rooy from comment #17)
} finally { $job->status('failed')->store if $job && @_;
Looks like a typo. Did you mean $@ ? And would testing that be enough or even appropriate in a finally block ?
Seeing comment6 now btw ;) -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #19 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- (In reply to Kyle M Hall from comment #9)
Just a thought; removing that fork will cause the workers memory footprint to balloon as soon as the plugins require is evaluated which obviates the bug patch where you introduce the require. I think this pushes us farther in the direction of needing to ack each request before handling the job.
Looks like there is consensus on keeping the fork. The problem does not seem to be related to forking. Did you consider moving the ->ack before the process start as Kyle suggested? It is simpler than the current code with finally. And it is still possible to run the worker without rabbitmq to recover if really needed? -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145064|0 |1 is obsolete| | -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Failed QA |Needs Signoff -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #20 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Marcel de Rooy from comment #19)
(In reply to Kyle M Hall from comment #9)
Just a thought; removing that fork will cause the workers memory footprint to balloon as soon as the plugins require is evaluated which obviates the bug patch where you introduce the require. I think this pushes us farther in the direction of needing to ack each request before handling the job.
Looks like there is consensus on keeping the fork. The problem does not seem to be related to forking. Did you consider moving the ->ack before the process start as Kyle suggested? It is simpler than the current code with finally. And it is still possible to run the worker without rabbitmq to recover if really needed?
See bug 32573. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |32594 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32594 [Bug 32594] Add a dedicated ES indexing background worker -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #21 from David Cook <dcook@prosentient.com.au> --- (In reply to Martin Renvoize from comment #12)
There's scope creep here.. the try encompasses the process_job which means it's also catching all sorts of other possible failures from each and every processor that's written.
I think we should limit the scope of this bug to only catch bad JSON encoding and leave error handling for individual tasks to the tasks themselves.
Actually, after looking at the code again, I think that Martin might be right. I'd have to test it, but in theory the forked process won't hit the "exit" in process_job if it throws a fatal error. Ah and that will be why you get that 2nd ACK. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 David Cook <dcook@prosentient.com.au> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Failed QA --- Comment #22 from David Cook <dcook@prosentient.com.au> --- So I think we should just wrap try{} around the code for getting $job. If we catch an error retrieving $job, then we log a warning. -- If we want to fail a job based on a fatal error in $job->process(), then we need to put a try/catch in the "process_job" function. It does need to be separate after all. I think we could rename this bug to be "Add exception handling to background jobs worker". (Note that this doesn't stop individual jobs from doing their own exception handling within the "process" function. This would just provide default exception handling.) -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #23 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145207 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145207&action=edit Bug 32393: Split into 2 try catch blocks -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Failed QA |Needs Signoff --- Comment #24 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- I don't understand what you are asking for guys. I've written a follow-up patch that I think does what you want, but I don't see how it is better. Note that now we are acking early. Please provide your own version if you are still disagreeing with the patches. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Nick Clemens <nick@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Needs Signoff |Signed Off -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Nick Clemens <nick@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #144569|0 |1 is obsolete| | --- Comment #25 from Nick Clemens <nick@bywatersolutions.com> --- Created attachment 145216 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145216&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Nick Clemens <nick@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145207|0 |1 is obsolete| | --- Comment #26 from Nick Clemens <nick@bywatersolutions.com> --- Created attachment 145217 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145217&action=edit Bug 32393: Split into 2 try catch blocks Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Nick Clemens <nick@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |nick@bywatersolutions.com --- Comment #27 from Nick Clemens <nick@bywatersolutions.com> --- Testing notes: 1.b didn't work for me, I did: - my $json_args = $self->_json->encode($job_args); + #my $json_args = $self->_json->encode($job_args); + my $json_args=$job_args; To check the queues I just did: rabbitmqctl list_queues -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |32612 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32612 [Bug 32612] Koha background worker should log to the worker-error.log -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #28 from David Cook <dcook@prosentient.com.au> --- (In reply to Jonathan Druart from comment #24)
I don't understand what you are asking for guys. I've written a follow-up patch that I think does what you want, but I don't see how it is better.
Looks good. Thanks for that. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Severity|normal |critical --- Comment #29 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Upping the severity as jobs can get stuck and worker explodes. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #30 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- For me this statement is also in the scope of this report (but not touched yet): while ( my $job = $jobs->next ) { my $args = $job->json->decode($job->data); -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Signed Off |Failed QA -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32573 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #31 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Note that I agree with acking earlier. We do this implicitly here. This would obsolete the separate report (32573). -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Depends on| |32573 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32573 [Bug 32573] background_jobs_worker.pl should ACK a message before it forks and runs the job -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Failed QA |Signed Off -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145216|0 |1 is obsolete| | Attachment #145217|0 |1 is obsolete| | --- Comment #32 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145596 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145596&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #33 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145597 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145597&action=edit Bug 32393: Split into 2 try catch blocks Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #34 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145598 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145598&action=edit Bug 32393: Deal with the DB fallback part -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #35 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Marcel de Rooy from comment #31)
Note that I agree with acking earlier. We do this implicitly here. This would obsolete the separate report (32573).
Added the dependency. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #36 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Marcel de Rooy from comment #30)
For me this statement is also in the scope of this report (but not touched yet):
while ( my $job = $jobs->next ) { my $args = $job->json->decode($job->data);
Done. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.koha-community | |.org/bugzilla3/show_bug.cgi | |?id=32708 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Blocks| |32709 Referenced Bugs: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32709 [Bug 32709] Background job UI and REST API routes explode if JSON is incorrect -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- QA Contact|testopia@bugs.koha-communit |m.de.rooy@rijksmuseum.nl |y.org | -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Signed Off |Patch doesn't apply --- Comment #37 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Applying: Bug 32393: Prevent invalid job to block the job queue Using index info to reconstruct a base tree... M misc/background_jobs_worker.pl Falling back to patching base and 3-way merge... Auto-merging misc/background_jobs_worker.pl CONFLICT (content): Merge conflict in misc/background_jobs_worker.pl ++<<<<<<< HEAD + my $body = $frame->body; + my $args = decode_json($body); # TODO Should this be from_json? Check utf8 flag. + + # FIXME This means we need to have create the DB entry before + # It could work in a first step, but then we will want to handle job that will be created from the message received + my $job = Koha::BackgroundJobs->find($args->{job_id}); + + $conn->ack( { frame => $frame } ); # Acknowledge the message was received + process_job( $job, $args ); ++======= + my $job; + try { + my $body = $frame->body; + my $args = decode_json($body); # TODO Should this be from_json? Check utf8 flag. + + # FIXME This means we need to have create the DB entry before + # It could work in a first step, but then we will want to handle job that will be created from the message received + $job = Koha::BackgroundJobs->find($args->{job_id}); + + process_job( $job, $args ); + } catch { + Koha::Logger->get->warn(sprintf "Job and/or frame not processed - %s", $_); + } finally { + $job->status('failed')->store if $job && @_; + $conn->ack( { frame => $frame } ); + }; ++>>>>>>> Bug 32393: Prevent invalid job to block the job queue Here ack and process_job are reversing order again.. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145596|0 |1 is obsolete| | --- Comment #38 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145609 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145609&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145597|0 |1 is obsolete| | --- Comment #39 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145610 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145610&action=edit Bug 32393: Split into 2 try catch blocks Signed-off-by: Nick Clemens <nick@bywatersolutions.com> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145598|0 |1 is obsolete| | --- Comment #40 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- Created attachment 145611 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145611&action=edit Bug 32393: Deal with the DB fallback part -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Jonathan Druart <jonathan.druart+koha@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Patch doesn't apply |Signed Off -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Signed Off |BLOCKED --- Comment #41 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- QAing -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Patch complexity|--- |Small patch Status|BLOCKED |Passed QA -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145609|0 |1 is obsolete| | --- Comment #42 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 145613 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145613&action=edit Bug 32393: Prevent invalid job to block the job queue I have faced a problem when testing an incorrect version of bug 32370. The frame sent to the message broker was not a correct JSON encoded string, and its decoding was obviously failing, exploding the worker script. Additionally, as we don't send a ack for this frame, the next pull will result in processing the same message, and so in the same explosion. No more messages can be processed! This patch is logging the error and ack the message to the broker, in order to not get stuck. Test plan: 0. Dont' apply this patch 1. Enqueue a bad message a. Apply 32370 b. Comment the following line in Koha::BackgroundJob::enqueue $self->set_encoded_json_field( { data => $job_args, field => 'data' } ); c. restart_all d. Use the batch item modification tool to enqueue a new job => Notice the error in the log => Note that the status of the job is "new" => Inspect rabbitmq queue: % rabbitmq-plugins enable rabbitmq_management % rabbitmqadmin get queue=koha_kohadev-long_tasks You will notice there is a message in the "long_tasks" queue 2. Enqueue a good message a. Remove the change from 1.b b. restart_all c. Enqueue another job => Same error in the log => Both jobs are new => Inspect rabbitmq, there are 2 messages 3. Apply this patch 4. restart_all => Second (good) job is finished => rabbitmq long_tasks queue is empty We cannot mark the first job as done, we have no idea which job it was! QA: Note that this patch is dealing with another problem, not tested in this test plan. If an exception is not correctly caught by the ->process method of the job, we won't crash the worker. The job will be marked as failed. Signed-off-by: Nick Clemens <nick@bywatersolutions.com> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145610|0 |1 is obsolete| | --- Comment #43 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 145614 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145614&action=edit Bug 32393: Split into 2 try catch blocks Signed-off-by: Nick Clemens <nick@bywatersolutions.com> Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Marcel de Rooy <m.de.rooy@rijksmuseum.nl> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #145611|0 |1 is obsolete| | --- Comment #44 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 145615 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145615&action=edit Bug 32393: Deal with the DB fallback part Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #45 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- Created attachment 145616 --> https://bugs.koha-community.org/bugzilla3/attachment.cgi?id=145616&action=edit Bug 32393: (QA follow-up) Add explicit undef response in two catch blocks Do not implicitly depend on last statement returning nothing. Make it explicit. We want $args to be null here. Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl> -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #46 from Marcel de Rooy <m.de.rooy@rijksmuseum.nl> --- And now we still need the job list to not crash on bad job data ;) I thought that there was a report too? -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #47 from Jonathan Druart <jonathan.druart+koha@gmail.com> --- (In reply to Marcel de Rooy from comment #46)
And now we still need the job list to not crash on bad job data ;) I thought that there was a report too?
See bug 32709. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Tomás Cohen Arazi <tomascohen@gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Version(s)| |23.05.00 released in| | Status|Passed QA |Pushed to master -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #48 from Tomás Cohen Arazi <tomascohen@gmail.com> --- Pushed to master for 23.05. Nice work everyone, thanks! -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Matt Blenkinsop <matt.blenkinsop@ptfs-europe.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Version(s)|23.05.00 |23.05.00,22.11.03 released in| | Status|Pushed to master |Pushed to stable -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 --- Comment #49 from Matt Blenkinsop <matt.blenkinsop@ptfs-europe.com> --- Nice work everyone! Pushed to stable for 22.11.x -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Lucas Gass <lucas@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |lucas@bywatersolutions.com --- Comment #50 from Lucas Gass <lucas@bywatersolutions.com> --- If this needs to be backported for 22.05.x then I will need some help rebasing Bug 32394. -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Lucas Gass <lucas@bywatersolutions.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Version(s)|23.05.00,22.11.03 |23.05.00,22.11.03,22.05.10 released in| | Status|Pushed to stable |Pushed to oldstable --- Comment #51 from Lucas Gass <lucas@bywatersolutions.com> --- Backported to 22.05.x for upcoming 22.05.10 -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Bug 32393 depends on bug 32394, which changed state. Bug 32394 Summary: Long tasks queue is never used https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32394 What |Removed |Added ---------------------------------------------------------------------------- Status|Pushed to oldstable |RESOLVED Resolution|--- |FIXED -- You are receiving this mail because: You are watching all bug changes.
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32393 Arthur Suzuki <arthur.suzuki@biblibre.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|Pushed to oldstable |RESOLVED CC| |arthur.suzuki@biblibre.com Resolution|--- |FIXED --- Comment #52 from Arthur Suzuki <arthur.suzuki@biblibre.com> --- depends on 32394, can't apply to 21.11.x -- You are receiving this mail because: You are watching all bug changes.
participants (1)
-
bugzilla-daemon@bugs.koha-community.org