Bug 9293 - action_logs not tracking payments
Summary: action_logs not tracking payments
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Transaction logs (show other bugs)
Version: master
Hardware: All All
: P5 - low major (vote)
Assignee: Kyle M Hall
QA Contact: Jonathan Druart
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-12-14 19:52 UTC by Nicole C. Engard
Modified: 2014-05-26 21:04 UTC (History)
5 users (show)

See Also:
Change sponsored?: ---
Patch complexity: Small patch
Text to go in the release notes:
Version(s) released in:


Attachments
Bug 9293 - action_logs not tracking payments (12.59 KB, patch)
2013-01-17 13:36 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (13.09 KB, patch)
2013-01-17 13:49 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (17.44 KB, patch)
2013-02-05 17:55 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (18.02 KB, patch)
2013-02-05 18:00 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (18.18 KB, patch)
2013-02-05 18:03 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (14.80 KB, patch)
2013-02-07 14:14 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (14.80 KB, patch)
2013-02-07 14:19 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (14.84 KB, patch)
2013-02-28 17:11 UTC, MJ Ray (software.coop)
Details | Diff | Splinter Review
Bug 9293 - action_logs not tracking payments (14.90 KB, patch)
2013-03-04 08:42 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 Nicole C. Engard 2012-12-14 19:52:32 UTC
I have been checking the action_logs table to find payments and which user paid the fines, but I'm not seeing them at all. Below are my queries on the table. Logging is on, and it's tracking fines charged automatically and manually and it's tracking dropbox forgiving fines and writeoffs (i think). But not payments that I can see. The log should log all fines actions.


mysql> select timestamp, user, action, object, info from action_logs where module='FINES' and user != 0 limit 10;
+---------------------+--------+--------+---------+-----------------------------------------------------+
| timestamp           | user   | action | object  | info                                                |
+---------------------+--------+--------+---------+-----------------------------------------------------+
| 2012-09-02 11:40:50 | 146258 |        | 1058715 | due=09/01/2012 23:59  amount=0.1 itemnumber=252043  |
| 2012-09-02 11:41:51 | 146258 |        | 1034172 | due=08/24/2012 23:59  amount=0.9 itemnumber=468810  |
| 2012-09-02 11:43:23 | 146258 |        | 1098788 | due=02/06/2012 23:59  amount=3.00 itemnumber=292689 |
| 2012-09-02 11:44:48 | 146258 |        | 1098788 | due=01/30/2012 23:59  amount=3.00 itemnumber=395796 |
| 2012-09-02 11:45:09 | 146258 |        | 1034172 | due=08/24/2012 23:59  amount=0.9 itemnumber=486769  |
| 2012-09-02 11:47:06 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=491656  |
| 2012-09-02 11:47:12 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=526858  |
| 2012-09-02 11:47:16 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=537406  |
| 2012-09-02 11:47:22 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=511679  |
| 2012-09-02 11:47:41 | 146258 |        | 1098788 | due=02/06/2012 23:59  amount=3.00 itemnumber=489449 |
+---------------------+--------+--------+---------+-----------------------------------------------------+
10 rows in set (0.00 sec)

mysql> select timestamp, user, action, object, info from action_logs where module='FINES' and action='MODIFY' and user != 0 limit 10;
+---------------------+--------+--------+---------+-----------------------------------+
| timestamp           | user   | action | object  | info                              |
+---------------------+--------+--------+---------+-----------------------------------+
| 2012-09-02 11:51:09 | 146257 | MODIFY | 1149266 | Dropbox adjustment 0, item 399887 |
| 2012-09-02 11:51:18 | 146257 | MODIFY | 1149266 | Dropbox adjustment 0, item 537469 |
| 2012-09-02 11:51:23 | 146257 | MODIFY | 1066164 | Dropbox adjustment 0, item 4588   |
| 2012-09-02 11:56:03 | 146257 | MODIFY | 1104714 | Dropbox adjustment 0, item 541027 |
| 2012-09-02 11:56:12 | 146257 | MODIFY | 1104714 | Dropbox adjustment 0, item 12471  |
| 2012-09-02 11:57:03 | 146257 | MODIFY | 1182366 | Dropbox adjustment 0, item 84270  |
| 2012-09-02 11:58:51 | 146257 | MODIFY | 1033313 | Dropbox adjustment 0, item 331794 |
| 2012-09-02 11:59:27 | 146257 | MODIFY | 1066164 | Dropbox adjustment 0, item 538578 |
| 2012-09-02 12:01:12 | 146257 | MODIFY | 1149753 | Dropbox adjustment 0, item 190944 |
| 2012-09-02 14:17:32 | 146254 | MODIFY | 1052342 | Dropbox adjustment 0, item 553366 |
+---------------------+--------+--------+---------+-----------------------------------+
10 rows in set (0.00 sec)

Database changed
mysql> select timestamp, user, action, object, info from action_logs where module='FINES' and action='MODIFY' and user != 0 and info not like '%dropbox%' limit 10;
+---------------------+--------+--------+---------+-------------------------------+
| timestamp           | user   | action | object  | info                          |
+---------------------+--------+--------+---------+-------------------------------+
| 2012-09-04 08:38:51 | 146257 | MODIFY | 1175137 | Overdue forgiven: item 384714 |
| 2012-09-04 08:39:23 | 146257 | MODIFY | 1164307 | Overdue forgiven: item 205688 |
| 2012-09-04 08:40:24 | 146257 | MODIFY | 1175137 | Overdue forgiven: item 394110 |
| 2012-09-04 08:40:32 | 146257 | MODIFY | 1164307 | Overdue forgiven: item 93445  |
| 2012-09-04 08:40:36 | 146257 | MODIFY | 1164307 | Overdue forgiven: item 366920 |
| 2012-09-04 08:40:41 | 146257 | MODIFY | 1164307 | Overdue forgiven: item 373410 |
| 2012-09-04 09:14:13 | 146257 | MODIFY |  751038 | Overdue forgiven: item 372751 |
| 2012-09-04 09:18:16 | 146272 | MODIFY | 1180787 | Overdue forgiven: item 208422 |
| 2012-09-04 09:23:14 | 146272 | MODIFY | 1180787 | Overdue forgiven: item 517498 |
| 2012-09-04 09:25:53 | 146272 | MODIFY | 1180787 | Overdue forgiven: item 415316 |
+---------------------+--------+--------+---------+-------------------------------+
10 rows in set (0.01 sec)

mysql> select timestamp, user, action, object, info from action_logs where module='FINES' and action='MODIFY' and user != 0 and info not like '%dropbox%' and info not like '%forgiven%' limit 10;
Empty set (2.28 sec)

mysql> select timestamp, user, action, object, info from action_logs where module='FINES' and user != 0 and info not like '%dropbox%' and info not like '%forgiven%' limit 10;
+---------------------+--------+--------+---------+-----------------------------------------------------+
| timestamp           | user   | action | object  | info                                                |
+---------------------+--------+--------+---------+-----------------------------------------------------+
| 2012-09-02 11:40:50 | 146258 |        | 1058715 | due=09/01/2012 23:59  amount=0.1 itemnumber=252043  |
| 2012-09-02 11:41:51 | 146258 |        | 1034172 | due=08/24/2012 23:59  amount=0.9 itemnumber=468810  |
| 2012-09-02 11:43:23 | 146258 |        | 1098788 | due=02/06/2012 23:59  amount=3.00 itemnumber=292689 |
| 2012-09-02 11:44:48 | 146258 |        | 1098788 | due=01/30/2012 23:59  amount=3.00 itemnumber=395796 |
| 2012-09-02 11:45:09 | 146258 |        | 1034172 | due=08/24/2012 23:59  amount=0.9 itemnumber=486769  |
| 2012-09-02 11:47:06 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=491656  |
| 2012-09-02 11:47:12 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=526858  |
| 2012-09-02 11:47:16 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=537406  |
| 2012-09-02 11:47:22 | 146258 |        | 1058402 | due=09/01/2012 23:59  amount=0.1 itemnumber=511679  |
| 2012-09-02 11:47:41 | 146258 |        | 1098788 | due=02/06/2012 23:59  amount=3.00 itemnumber=489449 |
+---------------------+--------+--------+---------+-----------------------------------------------------+
10 rows in set (0.00 sec)
Comment 1 Kyle M Hall 2013-01-17 13:36:09 UTC Comment hidden (obsolete)
Comment 2 Kyle M Hall 2013-01-17 13:49:05 UTC Comment hidden (obsolete)
Comment 3 Liz Rea 2013-02-02 00:32:14 UTC
This patch certainly works, but I think the output in the log needs to be clearer. 

Where money is involved, you do not want *any* ambiguity as to what happened, and you average librarian is going to look at that and probably have trouble understanding what happened.

I know that the same output appears in other logs, but the other logs don't involve money and financial "paper trail."

Please make the output a bit easier to understand, something like "borrower: <name> Action: <paid, writeoff, etc> Amount: <amount>

It doesn't have to be exactly like that, but it should have those elements.
Comment 4 Kyle M Hall 2013-02-05 17:55:52 UTC Comment hidden (obsolete)
Comment 5 Kyle M Hall 2013-02-05 18:00:52 UTC Comment hidden (obsolete)
Comment 6 Kyle M Hall 2013-02-05 18:03:12 UTC Comment hidden (obsolete)
Comment 7 Kyle M Hall 2013-02-05 18:06:06 UTC
I think this new version will be more to your liking.

Kyle

(In reply to comment #3)
> This patch certainly works, but I think the output in the log needs to be
> clearer. 
> 
> Where money is involved, you do not want *any* ambiguity as to what
> happened, and you average librarian is going to look at that and probably
> have trouble understanding what happened.
> 
> I know that the same output appears in other logs, but the other logs don't
> involve money and financial "paper trail."
> 
> Please make the output a bit easier to understand, something like "borrower:
> <name> Action: <paid, writeoff, etc> Amount: <amount>
> 
> It doesn't have to be exactly like that, but it should have those elements.
Comment 8 Galen Charlton 2013-02-07 00:47:17 UTC
The patch has a *lot* of extraneous whitespace changes.  If you want to clean up whitespace in C4/Accounts.pm as part of this patch series, please break it up into two patches so that your functionality change (adding FinesLog) can be evaluated separately from whitespace cleanup.

Also, the patch includes this:

@@ -396,19 +460,37 @@ sub manualinvoice {
 
     if ( $itemnum ) {
         $desc .= ' ' . $itemnum;
-        my $sth = $dbh->prepare(
-            'INSERT INTO  accountlines
-                        (borrowernumber, accountno, date, amount, description, accounttype, amountoutstanding, itemnumber,notify_
-        VALUES (?, ?, now(), ?,?, ?,?,?,?,?,?)');
-     $sth->execute($borrowernumber, $accountno, $amount, $desc, $type, $amountleft, $itemnum,$notifyid, $note, $manager_id) || re
-  } else {
-    my $sth=$dbh->prepare("INSERT INTO  accountlines
+        my $sth = $dbh->prepare("
+            INSERT INTO  accountlines
+            (borrowernumber, accountno, date, amount, description, accounttype, amountoutstanding, itemnumber,notify_id, note, ma
+            VALUES (?, ?, now(), ?,?, ?,?,?,?,?,?)
+        ");
+        $sth->execute($borrowernumber, $accountno, $amount, $desc, $type, $amountleft, $itemnum,$notifyid, $note, $manager_id) ||
+    } else {
+        my $sth=$dbh->prepare("
+            INSERT INTO  accountlines

I really wish that whatever is going on here wasn't changing the single quotes to double quotes in the $dbh->prepare() statement -- that makes it marginally more vulnerable to an SQL injection if somebody slips up and introduces a variable inside the quotes.
Comment 9 Kyle M Hall 2013-02-07 14:14:18 UTC Comment hidden (obsolete)
Comment 10 Kyle M Hall 2013-02-07 14:19:00 UTC Comment hidden (obsolete)
Comment 11 Chris Cormack 2013-02-17 07:52:01 UTC
Comment on attachment 15136 [details] [review]
Bug 9293 - action_logs not tracking payments

Review of attachment 15136 [details] [review]:
-----------------------------------------------------------------

::: C4/Accounts.pm
@@ +25,5 @@
>  use C4::Members;
>  use C4::Circulation qw(ReturnLostItem);
> +use C4::Log qw(logaction);
> +
> +use Data::Dumper qw(Dumper);

This works, but since we already make use of Module::Load::Conditional in Koha, we could use it, and can_load to load Data::Dumper only if we need it ie

if (C4::Context->preference("FinesLog") ) {
can_load(Data::Dumper);
}

Probably not needed here, but every module we don't use that we load is a small performance hit
Comment 12 MJ Ray (software.coop) 2013-02-28 17:11:47 UTC Comment hidden (obsolete)
Comment 13 MJ Ray (software.coop) 2013-02-28 17:12:43 UTC
I might not have tested all the possible actions, but all the ones I tried seemed to work, and it's been waiting three weeks, so I'll sign it off.
Comment 14 Jonathan Druart 2013-03-01 11:26:06 UTC
Hi Kyle,
Don't you think JSON::to_json is more adapted than Data::Dumper::Dumper here?
Comment 15 Kyle M Hall 2013-03-01 18:02:02 UTC
(In reply to comment #14)
> Hi Kyle,
> Don't you think JSON::to_json is more adapted than Data::Dumper::Dumper here?

I think that's a great idea, but Dumper is currently the way most everything is stored for the action logs. Perhaps we should submit a bug to switch everything to that and have it depend on this bug. We would have to have updatedatabase convert everything that is already in the action logs as well.
Comment 16 Jonathan Druart 2013-03-04 08:41:54 UTC
Kyle, in master, Dumper is used only 1 time with logaction. But it is not blocker.

QA comment:

This patch adds some logs for payments, it is clean and seems to work as expected.
I am not familiar with this module (Accounts.pm) so I don't know if I tested all cases.
It is a small patch and it will not introduce regression so I mark it as Passed QA.
Comment 17 Jonathan Druart 2013-03-04 08:42:22 UTC
Created attachment 15839 [details] [review]
Bug 9293 - action_logs not tracking payments

Add all fine actions to action_logs via FinesLog syspref

Test Plan:
1) Enable FinesLog
2) Apply patch
3) Try all the various fine related actions possible
4) Verify that each action creates an action_logs entry

Signed-off-by: MJ Ray <mjr@phonecoop.coop>
Signed-off-by: Jonathan Druart <jonathan.druart@biblibre.com>
Comment 18 Jared Camins-Esakov 2013-03-11 21:59:54 UTC
This patch has been pushed to master.