Bug 33309 - Race condition while checkout renewal with ES
Summary: Race condition while checkout renewal with ES
Status: RESOLVED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Architecture, internals, and plumbing (show other bugs)
Version: Main
Hardware: All All
: P3 major
Assignee: Nick Clemens (kidclamp)
QA Contact: Testopia
URL:
Keywords: rel_22_11_candidate
Depends on:
Blocks:
 
Reported: 2023-03-22 16:10 UTC by Janusz Kaczmarek
Modified: 2023-12-28 20:44 UTC (History)
5 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
23.05.00,22.11.05,22.05.12,21.11.20
Circulation function:


Attachments
Bug 33309: Index items after renewal transaction completes (2.60 KB, patch)
2023-03-22 19:14 UTC, Nick Clemens (kidclamp)
Details | Diff | Splinter Review
Bug 33309: Index items after renewal transaction completes (2.66 KB, patch)
2023-03-22 21:39 UTC, Janusz Kaczmarek
Details | Diff | Splinter Review
Bug 33309: Index items after renewal transaction completes (2.73 KB, patch)
2023-03-23 11:19 UTC, Jonathan Druart
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Janusz Kaczmarek 2023-03-22 16:10:04 UTC
Performing checkout renewal with ES turned on causes race condition in BackgroundJobs processing, manifesting with lines like:

[2023/03/20 17:18:10] [WARN] No job found for id=13218 main:: /usr/share/koha/bin/background_jobs_worker.pl (114)

in worker-output.log.

This is due to calling -- inside transaction -- $item_object->store in C4::Circulation::AddRenewal.  [Koha::Item->store in turn calls $indexer->index_records, which in installations with ES creates BackgroundJob].

The solution could be similar to that proposed in Bug 33019, i.e. calling $item_object->store with {skip_record_index => 1} and calling $indexer->index_records after the transaction ends.
Comment 1 Nick Clemens (kidclamp) 2023-03-22 19:14:54 UTC
Created attachment 148569 [details] [review]
Bug 33309: Index items after renewal transaction completes

This patch ensures a record is indexed only after the renewal transaction
has completed successfully. Otherwise the job cannot be found by the background process
worker, becaue it was not yet in the DB

To test:
1 - Make sure you are using ES, and the es indexer is running
2 - tail -f /var/log/koha/kohadev/*.log
3 - Issue an item to a patron and renew it
4 - Note error in es-indexer-output.log like:
    [2023/03/21 12:22:36] [WARN] No job found for id=157 main:: /kohadevbox/koha/misc/workers/es_indexer_daemon.pl (129)
5 - Apply patch
6 - Renew again
7  There should be no error
8 - Search for the record and confirm items info displays correctly
9 - View the background jobs in admin, confirm the most recent job has completed
Comment 2 Janusz Kaczmarek 2023-03-22 21:26:37 UTC
The only comment I would have for the testers -- since it is a race condition, not for every renewal would happen the issue signalized by "No job found for id=nnn"; sometimes everything would proceed smoothly.
Comment 3 Janusz Kaczmarek 2023-03-22 21:39:52 UTC
Created attachment 148573 [details] [review]
Bug 33309: Index items after renewal transaction completes

This patch ensures a record is indexed only after the renewal transaction
has completed successfully. Otherwise the job cannot be found by the background process
worker, becaue it was not yet in the DB

To test:
1 - Make sure you are using ES, and the es indexer is running
2 - tail -f /var/log/koha/kohadev/*.log
3 - Issue an item to a patron and renew it
4 - Note error in es-indexer-output.log like:
    [2023/03/21 12:22:36] [WARN] No job found for id=157 main:: /kohadevbox/koha/misc/workers/es_indexer_daemon.pl (129)
5 - Apply patch
6 - Renew again
7  There should be no error
8 - Search for the record and confirm items info displays correctly
9 - View the background jobs in admin, confirm the most recent job has completed

Signed-off-by: Janusz Kaczmarek <januszop@gmail.com>
Comment 4 Jonathan Druart 2023-03-23 11:19:40 UTC
Created attachment 148605 [details] [review]
Bug 33309: Index items after renewal transaction completes

This patch ensures a record is indexed only after the renewal transaction
has completed successfully. Otherwise the job cannot be found by the background process
worker, becaue it was not yet in the DB

To test:
1 - Make sure you are using ES, and the es indexer is running
2 - tail -f /var/log/koha/kohadev/*.log
3 - Issue an item to a patron and renew it
4 - Note error in es-indexer-output.log like:
    [2023/03/21 12:22:36] [WARN] No job found for id=157 main:: /kohadevbox/koha/misc/workers/es_indexer_daemon.pl (129)
5 - Apply patch
6 - Renew again
7  There should be no error
8 - Search for the record and confirm items info displays correctly
9 - View the background jobs in admin, confirm the most recent job has completed

Signed-off-by: Janusz Kaczmarek <januszop@gmail.com>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Comment 5 Tomás Cohen Arazi (tcohen) 2023-03-27 10:06:36 UTC
Pushed to master for 23.05.

Nice work everyone, thanks!
Comment 6 Matt Blenkinsop 2023-04-11 08:54:43 UTC
Nice work everyone!

Pushed to stable for 22.11.x
Comment 7 Lucas Gass (lukeg) 2023-04-24 16:59:42 UTC
Backported to 22.05.x for upcoming 22.05.12
Comment 8 Arthur Suzuki 2023-05-03 18:38:18 UTC
applied to 21.11.x for 21.11.20