Bug 28158

Summary: Lost items not charging when marked lost from batch item modification
Product: Koha Reporter: Nick Clemens <nick>
Component: ToolsAssignee: Jonathan Druart <jonathan.druart>
Status: CLOSED FIXED QA Contact: Testopia <testopia>
Severity: critical    
Priority: P5 - low CC: fridolin.somers, jonathan.druart, kyle, martin.renvoize, nick, tomascohen, victor
Version: master   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=28209
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=27707
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=17427
Change sponsored?: --- Patch complexity: ---
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
21.05.00
Bug Depends on:    
Bug Blocks: 28445, 28745    
Attachments: Bug 28158: Remove backgroundjob from batchMod
Bug 28158: Remove backgroundjob from batchMod
Bug 28158: Remove additional backgroundjob related code
Bug 28158: Remove additional backgroundjob related code
Bug 28158: [alternate] Use try/catch instead of eval
Bug 28158: Remove backgroundjob from batchMod
Bug 28158: Remove additional backgroundjob related code
Bug 28158: Allow batchMod to run under plack
Bug 28158: Remove backgroundjob from batchMod
Bug 28158: Remove additional backgroundjob related code
Bug 28158: Allow batchMod to run under plack

Description Nick Clemens 2021-04-16 16:00:30 UTC
This is a regression - the functionality works in 20.05 and 20.11

To test:
1 - In the default framework make sure the 952$1 is visible in opac/catalog/editor
2 - Set WhenLostChargeReplacementFee to charge
3 - Find an item with a replacement cost
4 - Check out the item to a patron
5 - Set MarkLostitemsAsReturned to return from batch modification
6 - Batch modify the item
7 - Set the lost status
8 - Item is not returned or charged
Comment 1 Martin Renvoize 2021-04-23 15:58:42 UTC
One for Monday and a fresh brain ;P
Comment 2 Martin Renvoize 2021-04-28 13:05:00 UTC
Struggling with this one..

If I add a bunch of warnings in.. I have to trigger the job to run in the foreground (else we throw away the warnings into a black hole)..

It all works perfectly.. revert it to using background processing.. the item gets marked as lost.. the return happens.. but the fee is NOT charged!

Completely confused..
Comment 3 Nick Clemens 2021-04-28 14:50:53 UTC
I used Koha::Logger to trace the brackground job execution

The eval around line 306 seems to catch an error from ModItemFromMarc:

[2021/04/28 14:43:28] [WARN] DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_0 does not exist [for Statement "RELEASE SAVEPOINT savepoint_0"] at /kohadevbox/koha/Koha/Object.pm line 169
 main::__ANON__ /kohadevbox/koha/tools/batchMod.pl (328) 

This does not happen if you force the job to the foreground:
1 - Set up your changes
2 - Inspect and edit the form
3 - Delete the hidden param 'runinbrackground'
4 - Force runinbackground to 0 in the form action:
    action="batchMod.pl?runinbrackground=0"
Comment 4 Jonathan Druart 2021-05-24 12:28:59 UTC
Investigated a bit here. It's a bit crazy when you read the DBIC_TRACE:

BEGIN WORK
SAVEPOINT savepoint_0
UPDATE `items` SET `cn_sort` = ?, `itemlost` = ?, `itemlost_on` = ? WHERE ( `itemnumber` = ? ): 'CN_1', '1', '2021-05-
24 12:20:47', '1'
RELEASE SAVEPOINT savepoint_0
DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_0 
does not exist [for Statement "RELEASE SAVEPOINT savepoint_0"]

(then the rollback fails)
ROLLBACK
rollback ineffective with AutoCommit enabled

But my guess is that this is caused by the fork, and more precisely the following statement:
  $job->progress($i) if $runinbackground;
It is retrieving the session (in the DB is SessionStorage is MySQL), and the SAVEPOINT does no longer exist.

I confirmed that switching SessionStorage to Memcached and I don't see the RELEASE error.

The long-term solution is obviously to implement the (new) background job, but here we need a quick fix.
I don't have much to suggest. Either we remove the transaction (and so the correct error handling/rollback), or we remove the progress.

We would opt for the latter, removing the transaction is a step backward.

This is definitely blocker for the release.
Comment 5 Tomás Cohen Arazi 2021-05-24 13:09:35 UTC
(In reply to Jonathan Druart from comment #4) 
>
> The long-term solution is obviously to implement the (new) background job,
> but here we need a quick fix.

-.-
Comment 6 Jonathan Druart 2021-05-24 13:16:48 UTC
Another solution is to replace CGI::Session, see bug 17427 comment 0
"If AutoCommit is off, it will commit anyway..."
Comment 7 Martin Renvoize 2021-05-24 14:03:10 UTC
I think drop progress for release, then look at dropping CGI::Session or migrating to Background job for .01 perhaps.  


Down with CGI baggage.. hehe
Comment 8 Jonathan Druart 2021-05-24 14:15:36 UTC
(In reply to Jonathan Druart from comment #6)
> Another solution is to replace CGI::Session, see bug 17427 comment 0
> "If AutoCommit is off, it will commit anyway..."

I rebased the patch there, and it does not fix the problem for us here.
Comment 9 Jonathan Druart 2021-05-24 14:22:48 UTC
Another bad news, it's not only the progress, but also the report.

Both $job->progress and $job->set create the problem apparently.
Comment 10 Jonathan Druart 2021-05-24 14:35:14 UTC Comment hidden (obsolete)
Comment 11 Jonathan Druart 2021-05-24 14:37:27 UTC Comment hidden (obsolete)
Comment 12 Jonathan Druart 2021-05-24 14:54:07 UTC
Created attachment 121340 [details] [review]
Bug 28158: Remove backgroundjob from batchMod
Comment 13 Jonathan Druart 2021-05-24 14:54:29 UTC
This patch is rude and I am open to any other alternatives.
Comment 14 Victor Grousset/tuxayo 2021-05-25 01:34:13 UTC
Created attachment 121345 [details] [review]
Bug 28158: Remove backgroundjob from batchMod

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 15 Jonathan Druart 2021-05-25 07:21:04 UTC
Created attachment 121352 [details] [review]
Bug 28158: Remove additional backgroundjob related code
Comment 16 Jonathan Druart 2021-05-25 07:23:33 UTC
I am considering this ready for signoff, because we are only few days before the release. I am still hopping for a better alternative solution however.

This patch removes code related to "extra_headers", coming from bug 19889. I don't understand what it was trying to achieve but I don't think it was working, please confirm if you are familiar with that code.
Comment 17 Jonathan Druart 2021-05-25 07:26:57 UTC
Created attachment 121353 [details] [review]
Bug 28158: Remove additional backgroundjob related code
Comment 18 Nick Clemens 2021-05-25 10:00:19 UTC
Created attachment 121366 [details] [review]
Bug 28158: [alternate] Use try/catch instead of eval

This could be improved, we could actually handle any exceptions,
but switching to 'try/catch' seems to resolve the issue
Comment 19 Nick Clemens 2021-05-25 10:17:07 UTC
(In reply to Nick Clemens from comment #18)
> Created attachment 121366 [details] [review] [review]
> Bug 28158: [alternate] Use try/catch instead of eval
> 
> This could be improved, we could actually handle any exceptions,
> but switching to 'try/catch' seems to resolve the issue

NVM, I can't make the problem happen without this, I am doing something...right/wrong
Comment 20 Nick Clemens 2021-05-25 11:15:50 UTC
Created attachment 121367 [details] [review]
Bug 28158: Remove backgroundjob from batchMod

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 21 Nick Clemens 2021-05-25 11:15:54 UTC
Created attachment 121368 [details] [review]
Bug 28158: Remove additional backgroundjob related code

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 22 Jonathan Druart 2021-05-25 11:56:03 UTC
Created attachment 121369 [details] [review]
Bug 28158: Allow batchMod to run under plack
Comment 23 Victor Grousset/tuxayo 2021-05-26 09:48:22 UTC
Created attachment 121415 [details] [review]
Bug 28158: Remove backgroundjob from batchMod

== Test plan ==
1 - In the default framework make sure the 952$1 is visible in opac & catalog & editor
2 - Set WhenLostChargeReplacementFee to charge
3 - Set MarkLostitemsAsReturned to return from batch modification
4 - Find/edit an item with a replacement cost
5 - Check out the item to a patron
6 - Batch modify the item
7 - Set the lost status
8 - Item is not returned or charged
9 - with the patch, it is

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 24 Victor Grousset/tuxayo 2021-05-26 09:48:27 UTC
Created attachment 121416 [details] [review]
Bug 28158: Remove additional backgroundjob related code

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 25 Victor Grousset/tuxayo 2021-05-26 09:48:31 UTC
Created attachment 121417 [details] [review]
Bug 28158: Allow batchMod to run under plack

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 26 Victor Grousset/tuxayo 2021-05-26 09:50:52 UTC
Still works as expected. Added test plan to 1st commit.

No grasp of the code, though that's still a signoff that allows Nick or someone else to QA.
Comment 27 Nick Clemens 2021-05-26 14:45:39 UTC
I think I agree with Jonathan here, this fix is not the best, I expect we might see some timeouts on large batches, but this is better than silently failing to charge as expected.

Moving my SO to PQA, feel free to ask for another pair of eyes Jonathan
Comment 28 Martin Renvoize 2021-05-27 07:19:20 UTC
I agree with Nick.. I've been testing it yesterday and so far it all worked reasonably well, but I've not had a massive batch to play with yet..

I'll add my QA SO lines this morning after the school run ;)
Comment 29 Jonathan Druart 2021-05-27 13:10:22 UTC
Pushed to master for 21.05, thanks to everybody involved!
Comment 30 Fridolin Somers 2021-05-31 14:38:20 UTC
Pushed to 20.11.x for 20.11.07
Comment 31 Jonathan Druart 2021-06-02 14:08:37 UTC
(In reply to Fridolin Somers from comment #30)
> Pushed to 20.11.x for 20.11.07

I wouldn't have backported this, it's a big change. Moreover Nick reported that it was working on 20.11.
Comment 32 Victor Grousset/tuxayo 2021-06-08 23:12:19 UTC
Not backported to oldoldstable (20.05.x).
Comment 33 Fridolin Somers 2021-06-09 07:25:26 UTC
(In reply to Jonathan Druart from comment #31)
> (In reply to Fridolin Somers from comment #30)
> > Pushed to 20.11.x for 20.11.07
> 
> I wouldn't have backported this, it's a big change. Moreover Nick reported
> that it was working on 20.11.

OK I revert.