Bug 32306

Summary: Hold modifications don't log correctly
Product: Koha Reporter: Emmi Takkinen <emmi.takkinen>
Component: Transaction logsAssignee: Emmi Takkinen <emmi.takkinen>
Status: In Discussion --- QA Contact: Kyle M Hall <kyle>
Severity: enhancement    
Priority: P5 - low CC: emily.lamancusa, jonathan.druart, kebliss, kyle, m.de.rooy, nick
Version: Main   
Hardware: All   
OS: All   
Change sponsored?: --- Patch complexity: ---
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
Attachments: Bug 32306: Add unit tests
Bug 32306: Log after storing changes in ModReserve
Bug 32306: Add unit tests
Bug 32306: Log after storing changes in ModReserve

Description Emmi Takkinen 2022-11-21 13:45:57 UTC
When one modifies holds from records holds page, these changes don't log into action_logs table correctly. Instead holds data before modifications is stored to action_logs.

To test:
1. Find hold to modify.
2. If possible, locate this hold from action_logs table:
SELECT * FROM action_logs WHERE module = "HOLDS" AND object = <reserve_id>; 
3. Modify hold, change its pickup library from A to B.
4. Save changes.
5. Take a look at action_logs table.
=> Modification is saved, but holds pickup library is still A.
6. Modify hold again, e.g add expiration date.
7. Save.
=> Expiration date is empty, but pickup library is now B.
Comment 1 Emmi Takkinen 2022-11-24 12:44:45 UTC
Created attachment 144215 [details] [review]
Bug 32306: Add unit tests

In ModReserves logging changes actually happens
before we store any of made changes.

To test:
1. Run prove t/db_dependent/Reserves.t
=> Tests should fail.

Sponsored-by: Koha-Suomi Oy
Comment 2 Emmi Takkinen 2022-11-24 12:45:27 UTC
Created attachment 144216 [details] [review]
Bug 32306: Log after storing changes in ModReserve

When one modifies holds from records holds page, these
changes don't log into action_logs table correctly.
Instead holds data before modifications is stored to action_logs.

This patch moves call for logaction after changes have
been stored in ModReserve.

To test:
1. Find hold to modify.
2. If possible, locate this hold from action_logs table:
SELECT * FROM action_logs WHERE module = "HOLDS" AND object = <reserve_id>;
3. Modify hold, change its pickup library from A to B.
4. Save changes.
5. Take a look at action_logs table.
=> Modification is saved, but holds pickup library is still A.
6. Modify hold again, e.g add expiration date.
7. Save.
8. Find this new modification from action_logs.
=> In action_logs table expiration date is empty, but pickup library is now B.
9. Apply this patch.
10. Modify hold, change its pickup library back from B to A.
11. Save changes.
=> In action_logs table holds modification has now a correct pickup library A.

Also prove t/db_dependent/Reserves.t.

Sponsored-by: Koha-Suomi Oy
Comment 3 Emily Lamancusa 2023-01-23 16:10:27 UTC
Created attachment 145587 [details] [review]
Bug 32306: Add unit tests

In ModReserves logging changes actually happens
before we store any of made changes.

To test:
1. Run prove t/db_dependent/Reserves.t
=> Tests should fail.

Sponsored-by: Koha-Suomi Oy
Comment 4 Emily Lamancusa 2023-01-23 16:10:31 UTC
Created attachment 145588 [details] [review]
Bug 32306: Log after storing changes in ModReserve

When one modifies holds from records holds page, these
changes don't log into action_logs table correctly.
Instead holds data before modifications is stored to action_logs.

This patch moves call for logaction after changes have
been stored in ModReserve.

To test:
1. Find hold to modify.
2. If possible, locate this hold from action_logs table:
SELECT * FROM action_logs WHERE module = "HOLDS" AND object = <reserve_id>;
3. Modify hold, change its pickup library from A to B.
4. Save changes.
5. Take a look at action_logs table.
=> Modification is saved, but holds pickup library is still A.
6. Modify hold again, e.g add expiration date.
7. Save.
8. Find this new modification from action_logs.
=> In action_logs table expiration date is empty, but pickup library is now B.
9. Apply this patch.
10. Modify hold, change its pickup library back from B to A.
11. Save changes.
=> In action_logs table holds modification has now a correct pickup library A.

Also prove t/db_dependent/Reserves.t.

Sponsored-by: Koha-Suomi Oy
Signed-off-by: Emily Lamancusa <emily.lamancusa@montgomerycountymd.gov>
Comment 5 Jonathan Druart 2023-02-23 14:38:34 UTC
Nick, do you see a good reason to log before the exp date is modified?
Comment 6 Nick Clemens 2023-02-23 14:55:10 UTC
(In reply to Jonathan Druart from comment #5)
> Nick, do you see a good reason to log before the exp date is modified?

I think we are inconsistent throughout the code of logging before or after actions.

On one hand - storing the before should provide info on what was changed by comparing to the current state

On the other, storing after means that the log preserves what was done

My preference would be to store both the before and after, or the diff to see what changed (storing both would allow front end diffing)

I think at a minimum adding a "BEFORE" or "AFTER" param to the info would at least make it obvious which we stored
Comment 7 Emily Lamancusa 2023-02-23 18:18:45 UTC
Is it worth reviving Bug 25159 for standardizing action logs as JSON diffs?
Comment 8 Emmi Takkinen 2023-02-24 07:47:40 UTC
(In reply to Nick Clemens from comment #6)

> My preference would be to store both the before and after, or the diff to
> see what changed (storing both would allow front end diffing)
> 

+1 for this. IMO trying to decide which logs should log after and which should log before changes would be almost impossible. Bug 25159 indeed looks like worth reviving as Emily suggested.

And don't we already do this with some logs? Yep, MEMBERS MODIFY looks like this:
> UPDATED FIELD(S): branchcode: A => B, dateexpiry: 2023-01-01 => 2024-01-01

This bug actually sparked a conversation at our end about saving only diff to the logs and we decided to work on this at some point. But we are currently in the middle of version change, we probably are able to work on this earliest in the summer.
Comment 9 Marcel de Rooy 2023-04-14 06:41:50 UTC
+                found            => "W",
+                priority         => 0,
+                itemnumber       => undef,

Waiting hold without an item number ??
Comment 10 Marcel de Rooy 2023-04-14 06:45:48 UTC
Not clear if we finished discussing the questions raised here.
=> In Discussion

Intuitively, this unit test feels too long (maintenance). Changing from BEFORE to AFTER for one specific case feels wrong too.
Comment 11 Katrin Fischer 2023-04-15 22:40:54 UTC
 
> And don't we already do this with some logs? Yep, MEMBERS MODIFY looks like
> this:
> > UPDATED FIELD(S): branchcode: A => B, dateexpiry: 2023-01-01 => 2024-01-01

I think changing to the way we log patron changes would be really nice and work well for holds changes. It logs before and after and is quite easy to read. But it looks a little differently for me?

{ "B_address" : { "after" : "", "before" : null }, "B_address2" : { "after" : "", "before" : null }, "B_city" : { "after" : "", "before" : null }, "B_country" : { "after" : "", "before" : null }, "B_email" : { "after" : "", "before" : null }, "B_phone" : { "after" : "", "before" : null }, "B_state" : { "after" : "", "before" : null }, "B_streetnumber" : { "after" : "", "before" : null }, ...
Comment 12 Emmi Takkinen 2023-08-11 07:45:02 UTC
I think it's save to say that this bug is a duplicate of bug 25159?