t/db_dependent/Log.t

   1 #!/usr/bin/perl
   2 #
   3 # This file is part of Koha.
   4 #
   5 # Koha is free software; you can redistribute it and/or modify it under the
   6 # terms of the GNU General Public License as published by the Free Software
   7 # Foundation; either version 3 of the License, or (at your option) any later
   8 # version.
   9 #
  10 # Koha is distributed in the hope that it will be useful, but WITHOUT ANY
  11 # WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR
  12 # A PARTICULAR PURPOSE. See the GNU General Public License for more details.
  13 #
  14 # You should have received a copy of the GNU General Public License along
  15 # with Koha; if not, see <http://www.gnu.org/licenses>.
  16
  17 use Modern::Perl;
  18 use Data::Dumper qw( Dumper );
  19 use Test::More tests => 6;
  20
  21 use C4::Context;
  22 use C4::Log qw( logaction cronlogaction );
  23 use C4::Auth qw( checkpw );
  24 use Koha::Database;
  25 use Koha::ActionLogs;
  26
  27 use t::lib::Mocks qw/mock_preference/; # to mock CronjobLog
  28 use t::lib::TestBuilder;
  29
  30 use JSON qw( decode_json );
  31
  32 # Make sure we can rollback.
  33 our $schema  = Koha::Database->new->schema;
  34 $schema->storage->txn_begin;
  35
  36 subtest 'Existing tests' => sub {
  37     plan tests => 3;
  38
  39     my $success;
  40     eval {
  41         # FIXME: are we sure there is an member number 1?
  42         logaction("MEMBERS","MODIFY",1,"test operation");
  43         $success = 1;
  44     } or do {
  45         diag($@);
  46         $success = 0;
  47     };
  48     ok($success, "logaction seemed to work");
  49
  50     # We want numbers to be the same between runs.
  51     Koha::ActionLogs->search->delete;
  52
  53     t::lib::Mocks::mock_preference('CronjobLog',0);
  54     cronlogaction();
  55     is(Koha::ActionLogs->search({ module => 'CRONJOBS' })->count,0,"Cronjob not logged as expected.");
  56
  57     t::lib::Mocks::mock_preference('CronjobLog',1);
  58     cronlogaction();
  59     is(Koha::ActionLogs->search({ module => 'CRONJOBS' })->count,1,"Cronjob logged as expected.");
  60 };
  61
  62 subtest 'logaction(): interface is correctly logged' => sub {
  63
  64     plan tests => 4;
  65
  66     # No interface passed, using C4::Context->interface
  67     Koha::ActionLogs->search->delete;
  68     C4::Context->interface( 'commandline' );
  69     logaction( "MEMBERS", "MODIFY", 1, "test operation");
  70     my $log = Koha::ActionLogs->search->next;
  71     is( $log->interface, 'commandline', 'Interface correctly deduced (commandline)');
  72
  73     # No interface passed, using C4::Context->interface
  74     Koha::ActionLogs->search->delete;
  75     C4::Context->interface( 'opac' );
  76     logaction( "MEMBERS", "MODIFY", 1, "test operation");
  77     $log = Koha::ActionLogs->search->next;
  78     is( $log->interface, 'opac', 'Interface correctly deduced (opac)');
  79
  80     # Explicit interfaces
  81     Koha::ActionLogs->search->delete;
  82     C4::Context->interface( 'intranet' );
  83     logaction( "MEMBERS", "MODIFY", 1, 'test info', 'intranet');
  84     $log = Koha::ActionLogs->search->next;
  85     is( $log->interface, 'intranet', 'Passed interface is respected (intranet)');
  86
  87     # Explicit interfaces
  88     Koha::ActionLogs->search->delete;
  89     C4::Context->interface( 'sip' );
  90     logaction( "MEMBERS", "MODIFY", 1, 'test info', 'sip');
  91     $log = Koha::ActionLogs->search->next;
  92     is( $log->interface, 'sip', 'Passed interface is respected (sip)');
  93 };
  94
  95 subtest 'logaction / trace' => sub {
  96     plan tests => 2;
  97
  98     C4::Context->interface( 'intranet' );
  99     t::lib::Mocks::mock_preference('ActionLogsTraceDepth',0);
 100
 101     logaction( "MEMBERS", "MODIFY", 1, "test1");
 102     is( Koha::ActionLogs->search({ info => 'test1' })->last->trace, undef, 'No trace at level 0' );
 103     t::lib::Mocks::mock_preference('ActionLogsTraceDepth',2);
 104     logaction( "MEMBERS", "MODIFY", 1, "test2");
 105     like( Koha::ActionLogs->search({ info => 'test2' })->last->trace, qr/("line":.*){2}/, 'Found two trace levels' );
 106
 107     t::lib::Mocks::mock_preference('ActionLogsTraceDepth',0);
 108 };
 109
 110 subtest 'GDPR logging' => sub {
 111     plan tests => 6;
 112
 113     my $builder = t::lib::TestBuilder->new;
 114     my $patron = $builder->build_object( { class => 'Koha::Patrons' } );
 115
 116     t::lib::Mocks::mock_userenv({ patron => $patron });
 117     logaction( 'AUTH', 'FAILURE', $patron->id, '', 'opac' );
 118     my $logs = Koha::ActionLogs->search(
 119         {
 120             user   => $patron->id,
 121             module => 'AUTH',
 122             action => 'FAILURE',
 123             object => $patron->id,
 124         }
 125     );
 126     is( $logs->count, 1, 'We should find one auth failure' );
 127
 128     t::lib::Mocks::mock_preference('AuthFailureLog', 1);
 129     my $strong_password = 'N0tStr0ngAnyM0reN0w:)';
 130     $patron->set_password({ password => $strong_password });
 131     my @ret = checkpw( $patron->userid, 'WrongPassword', undef, undef, 1);
 132     is( $ret[0], 0, 'Authentication failed' );
 133     # Look for auth failure but NOT on patron id, pass userid in info parameter
 134     $logs = Koha::ActionLogs->search(
 135         {
 136             module => 'AUTH',
 137             action => 'FAILURE',
 138             info   => { -like => '%'.$patron->userid.'%' },
 139         }
 140     );
 141     is( $logs->count, 1, 'We should find one auth failure with this userid' );
 142     t::lib::Mocks::mock_preference('AuthFailureLog', 0);
 143     @ret = checkpw( $patron->userid, 'WrongPassword', undef, undef, 1);
 144     $logs = Koha::ActionLogs->search(
 145         {
 146             module => 'AUTH',
 147             action => 'FAILURE',
 148             info   => { -like => '%'.$patron->userid.'%' },
 149         }
 150     );
 151     is( $logs->count, 1, 'Still only one failure with this userid' );
 152     t::lib::Mocks::mock_preference('AuthSuccessLog', 1);
 153     @ret = checkpw( $patron->userid, $strong_password, undef, undef, 1);
 154     is( $ret[0], 1, 'Authentication succeeded' );
 155     # Now we can look for patron id
 156     $logs = Koha::ActionLogs->search(
 157         {
 158             user   => $patron->id,
 159             module => 'AUTH',
 160             action => 'SUCCESS',
 161             object => $patron->id,
 162         }
 163     );
 164
 165     is( $logs->count, 1, 'We expect only one auth success line for this patron' );
 166 };
 167
 168 subtest 'Reduce log size by unblessing Koha objects' => sub {
 169     plan tests => 7;
 170
 171     my $builder = t::lib::TestBuilder->new;
 172     my $item = $builder->build_sample_item;
 173
 174     logaction( 'MY_MODULE', 'TEST01', $item->itemnumber, $item, 'opac' );
 175     my $str = Dumper($item->unblessed);
 176     my $logs = Koha::ActionLogs->search({ module => 'MY_MODULE', action => 'TEST01', object => $item->itemnumber });
 177     is( $logs->count, 1, 'Action found' );
 178     is( length($logs->next->info), length($str), 'Length exactly identical' );
 179
 180     logaction( 'CATALOGUING', 'MODIFY', $item->itemnumber, $item, 'opac' );
 181     $logs = Koha::ActionLogs->search({ module => 'CATALOGUING', action => 'MODIFY', object => $item->itemnumber });
 182     is( substr($logs->next->info, 0, 5), 'item ', 'Prefix item' );
 183     is( length($logs->reset->next->info), 5+length($str), 'Length + 5' );
 184
 185     my $hold = $builder->build_object({ class => 'Koha::Holds' });
 186     logaction( 'MY_CIRC_MODULE', 'TEST', $item->itemnumber, $hold, 'opac' );
 187     $logs = Koha::ActionLogs->search({ module => 'MY_CIRC_MODULE', action => 'TEST', object => $item->itemnumber });
 188     is( length($logs->next->info), length( Dumper($hold->unblessed)), 'Length of dumped unblessed hold' );
 189
 190     logaction( 'MY_MODULE', 'TEST02', $item->itemnumber, [], 'opac' );
 191     $logs = Koha::ActionLogs->search({ module => 'MY_MODULE', action => 'TEST02', object => $item->itemnumber });
 192     like( $logs->next->info, qr/^ARRAY\(/, 'Dumped arrayref' );
 193
 194     logaction( 'MY_MODULE', 'TEST03', $item->itemnumber, $builder, 'opac' );
 195     $logs = Koha::ActionLogs->search({ module => 'MY_MODULE', action => 'TEST03', object => $item->itemnumber });
 196     like( $logs->next->info, qr/^t::lib::TestBuilder/, 'Dumped TestBuilder object' );
 197 };
 198
 199 subtest 'Test storing diff of objects' => sub {
 200     plan tests => 2;
 201
 202     my $builder       = t::lib::TestBuilder->new;
 203     my $item          = $builder->build_sample_item;
 204     my $original      = $item->unblessed();
 205     my $original_item = $item->get_from_storage();
 206     $item->barcode('_MY_TEST_BARCODE_')->store();
 207
 208     logaction( 'MY_MODULE', 'TEST01', $item->itemnumber, $item, 'opac', $original );
 209     my $logs =
 210         Koha::ActionLogs->search( { module => 'MY_MODULE', action => 'TEST01', object => $item->itemnumber } )->next;
 211     my $diff = decode_json( $logs->diff );
 212     is( $diff->{D}->{barcode}->{N}, '_MY_TEST_BARCODE_', 'Diff of changes logged successfully' );
 213
 214     logaction( 'MY_MODULE', 'TEST02', $item->itemnumber, $item, 'opac', $original_item );
 215     $logs =
 216         Koha::ActionLogs->search( { module => 'MY_MODULE', action => 'TEST02', object => $item->itemnumber } )->next;
 217     $diff = decode_json( $logs->diff );
 218     is( $diff->{D}->{barcode}->{N}, '_MY_TEST_BARCODE_', 'Diff of changes logged successfully' );
 219 };
 220
 221 $schema->storage->txn_rollback;