Bug 32057: Add optional stack trace to action logs

It can be useful to know where in Koha a particular logged action was generated from, and how. We should add the ability to attach a syspref controlled basic stack trace with the caller depth controlled via the syspref. We can the call caller() until the specified depth has been reached.

Test Plan:
1) Apply this patch
2) Run updatedatabase.pl
4) Restart all the things!
5) Set the new syspref ActionLogsTraceDepth to a number ( e.g. 3 )
6) Update a syspref or trigger another enabled log action
7) Query the database: SELECT * FROM action_logs WHERE trace IS NOT NULL
8) Note the stack trace was created!

Signed-off-by: David Nind <david@davidnind.com>
Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>

diff --git a/C4/Log.pm b/C4/Log.pm
index cff2931..6cddc5a 100644 (file)
--- a/C4/Log.pm
+++ b/C4/Log.pm
@@ -94,9 +94,26 @@ sub logaction {
         ? basename($0)
         : undef;
 
+    my @trace;
+    my $depth = C4::Context->preference('ActionLogsTraceDepth') || 0;
+    for ( my $i = 0 ; $i < $depth ; $i++ ) {
+        my ( $package, $filename, $line, $subroutine ) = caller($i);
+        last unless defined $line;
+        push(
+            @trace,
+            {
+                package    => $package,
+                filename   => $filename,
+                line       => $line,
+                subroutine => $subroutine,
+            }
+        );
+    }
+    my $trace = @trace ? to_json( \@trace, { utf8 => 1, pretty => 1 } ) : undef;
+
     my $dbh = C4::Context->dbh;
-    my $sth=$dbh->prepare("Insert into action_logs (timestamp,user,module,action,object,info,interface,script) values (now(),?,?,?,?,?,?,?)");
-    $sth->execute($usernumber,$modulename,$actionname,$objectnumber,$infos,$interface,$script);
+    my $sth=$dbh->prepare("Insert into action_logs (timestamp,user,module,action,object,info,interface,script,trace) values (now(),?,?,?,?,?,?,?,?)");
+    $sth->execute( $usernumber, $modulename, $actionname, $objectnumber, $infos, $interface, $script, $trace );
     $sth->finish;
 
     my $logger = Koha::Logger->get(

diff --git a/installer/data/mysql/atomicupdate/bug_32057.pl b/installer/data/mysql/atomicupdate/bug_32057.pl
new file mode 100755 (executable)
index 0000000..c160a82
--- /dev/null
+++ b/installer/data/mysql/atomicupdate/bug_32057.pl
@@ -0,0 +1,21 @@
+use Modern::Perl;
+
+return {
+    bug_number => "32057",
+    description => "Bug 32057 - Add optional stack trace to action logs",
+    up => sub {
+        my ($args) = @_;
+        my $dbh = $args->{dbh};
+
+        if( !column_exists( 'action_logs', 'trace' ) ) {
+          $dbh->do(q{
+              ALTER TABLE action_logs ADD COLUMN `trace` TEXT DEFAULT NULL COMMENT 'An optional stack trace enabled by ActionLogsTraceDepth' AFTER `script`
+          });
+        }
+
+        $dbh->do(q{
+            INSERT INTO systempreferences ( `variable`, `value`, `options`, `explanation`, `type` ) VALUES
+            ('ActionLogsTraceDepth', '0', '', 'Sets the maximum depth of the action logs stack trace', 'Integer')
+        });
+    },
+}

diff --git a/installer/data/mysql/kohastructure.sql b/installer/data/mysql/kohastructure.sql
index afbd7e1..a3faa37 100644 (file)
--- a/installer/data/mysql/kohastructure.sql
+++ b/installer/data/mysql/kohastructure.sql
@@ -171,6 +171,7 @@ CREATE TABLE `action_logs` (
   `info` mediumtext DEFAULT NULL COMMENT 'information about the action (usually includes SQL statement)',
   `interface` varchar(30) DEFAULT NULL COMMENT 'the context this action was taken in',
   `script` varchar(255) DEFAULT NULL COMMENT 'the name of the cron script that caused this change',
+  `trace` TEXT DEFAULT NULL COMMENT 'An optional stack trace enabled by ActionLogsTraceDepth',
   PRIMARY KEY (`action_id`),
   KEY `timestamp_idx` (`timestamp`),
   KEY `user_idx` (`user`),

diff --git a/installer/data/mysql/mandatory/sysprefs.sql b/installer/data/mysql/mandatory/sysprefs.sql
index b12f1ce..98eced6 100644 (file)
--- a/installer/data/mysql/mandatory/sysprefs.sql
+++ b/installer/data/mysql/mandatory/sysprefs.sql
@@ -9,6 +9,7 @@ INSERT INTO systempreferences ( `variable`, `value`, `options`, `explanation`, `
 ('AcquisitionLog','0',NULL,'If ON, log acquisitions activity','YesNo'),
 ('AcqViewBaskets','user','user|branch|all','Define which baskets a user is allowed to view: their own only, any within their branch, or all','Choice'),
 ('AcqWarnOnDuplicateInvoice','0','','Warn librarians when they try to create a duplicate invoice','YesNo'),
+('ActionLogsTraceDepth', '0', '', 'Sets the maximum depth of the action logs stack trace', 'Integer'),
 ('AdditionalContentsEditor','tinymce','tinymce|codemirror','Choose tool for editing News.', 'Choice'),
 ('AdditionalFieldsInZ3950ResultSearch', '', NULL, 'Determines which MARC field/subfields are displayed in -Additional field- column in the result of a search Z3950', 'Free'),
 ('AddressForFailedOverdueNotices', '', NULL, 'Destination email for failed overdue notices. If left empty then it will fallback to the first defined address in the following list: Library ReplyTo, Library Email, ReplytoDefault and KohaAdminEmailAddress', 'free'),

diff --git a/koha-tmpl/intranet-tmpl/prog/en/modules/admin/preferences/logs.pref b/koha-tmpl/intranet-tmpl/prog/en/modules/admin/preferences/logs.pref
index ccb11bc..8337b78 100644 (file)
--- a/koha-tmpl/intranet-tmpl/prog/en/modules/admin/preferences/logs.pref
+++ b/koha-tmpl/intranet-tmpl/prog/en/modules/admin/preferences/logs.pref
@@ -117,6 +117,11 @@ Logging:
 
     Debugging:
         -
+            - "When logging actions, store a stack trace that goes at most"
+            - pref: "ActionLogsTraceDepth"
+              class: integer
+            - "levels deep."
+        -
             - pref: DumpTemplateVarsIntranet
               choices:
                   1: Do