Bug 20750 - Allow timestamped auditing of ILL request events
Summary: Allow timestamped auditing of ILL request events
Status: Signed Off
Alias: None
Product: Koha
Classification: Unclassified
Component: ILL (show other bugs)
Version: master
Hardware: All All
: P5 - low enhancement (vote)
Assignee: Andrew Isherwood
QA Contact:
URL:
Whiteboard:
Keywords:
: 21461 (view as bug list)
Depends on: 20639 7317
Blocks: 21063
  Show dependency treegraph
 
Reported: 2018-05-10 11:25 UTC by Andrew Isherwood
Modified: 2018-10-19 09:47 UTC (History)
3 users (show)

See Also:
Change sponsored?: ---
Patch complexity: Small patch
Bot Control: ---
When did the bot last check this:
Who signed the patch off:
Text to go in the release notes:


Attachments
Bug 20750: Allow logging of arbitrary actions (17.19 KB, patch)
2018-05-14 13:37 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (23.44 KB, patch)
2018-05-15 11:19 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Squashed commit for ILL enhancements (20.33 KB, patch)
2018-05-15 13:12 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.62 KB, patch)
2018-05-15 13:15 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.93 KB, patch)
2018-08-13 15:30 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.93 KB, patch)
2018-08-15 14:44 UTC, PTFS Europe Sandboxes
Details | Diff | Splinter Review
Signed-off-by: Niamh Walker <Niamh.Walker-Headon@it-tallaght.ie> (20.00 KB, patch)
2018-08-15 14:46 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.93 KB, patch)
2018-08-15 14:50 UTC, PTFS Europe Sandboxes
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (20.00 KB, patch)
2018-08-16 14:55 UTC, PTFS Europe Sandboxes
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.42 KB, patch)
2018-10-02 13:58 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Add unit tests (5.65 KB, patch)
2018-10-02 13:58 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: Allow logging of arbitrary actions (19.49 KB, patch)
2018-10-02 14:04 UTC, Andrew Isherwood
Details | Diff | Splinter Review
Bug 20750: (follow-up) Fix sorting of log entries (1.40 KB, patch)
2018-10-18 15:10 UTC, Andrew Isherwood
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Andrew Isherwood 2018-05-10 11:25:12 UTC
Currently there is no audit trail provided for ILL requests, this is required.

At the most basic form this would be a timestamped record of changes of a request's status. It would be useful to be able to also record other arbitrary events.

This bug proposes the addition of a requests_actions log that allows either the core ILL code or backends to record arbitrary events relating to a request. This could then be displayed in the UI as an "audit trail" or reported upon.
Comment 1 Andrew Isherwood 2018-05-10 14:13:48 UTC
Discussed with joubu on IRC, suggestion was to use actions_logs rather than bake our own recording mechanism
Comment 2 Magnus Enger 2018-05-11 09:01:26 UTC
Sounds like a most excellent idea! Would this include some kind of diff between old and new metadata when a request is updated? That would be awesome!
Comment 3 Andrew Isherwood 2018-05-11 10:57:38 UTC
The initial implementation will only log status changes and this will indeed record "before" and "after" statuses. I'm implementing it in as extensible a way as possible to allow other events/actions to be logged with whatever data is required
Comment 4 Andrew Isherwood 2018-05-14 13:37:32 UTC Comment hidden (obsolete)
Comment 5 Magnus Enger 2018-05-14 18:46:04 UTC Comment hidden (obsolete)
Comment 6 Magnus Enger 2018-05-14 18:51:07 UTC Comment hidden (obsolete)
Comment 7 Magnus Enger 2018-05-14 18:52:45 UTC Comment hidden (obsolete)
Comment 8 Andrew Isherwood 2018-05-15 11:18:20 UTC Comment hidden (obsolete)
Comment 9 Andrew Isherwood 2018-05-15 11:19:42 UTC Comment hidden (obsolete)
Comment 10 Magnus Enger 2018-05-15 12:43:38 UTC Comment hidden (obsolete)
Comment 11 Andrew Isherwood 2018-05-15 13:12:18 UTC Comment hidden (obsolete)
Comment 12 Andrew Isherwood 2018-05-15 13:15:46 UTC
Created attachment 75330 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.
Comment 13 Andrew Isherwood 2018-05-15 13:18:49 UTC
Well spotted Magnus, thanks! I've submitted a new patch which removes changes to Schema files.

Also, ignore comment #11 and attachment #75329 [details] [review] - over zealous fingers typing faster than my brain...
Comment 14 Magnus Enger 2018-05-22 07:28:12 UTC
From looking at the code, it seems that the test plan only covers part of the functionality, that of keeping a record of the actual status of a request. It looks like the new code can also track changes to the other parts of the metadata. Is this correct, and would it be possible to enhance the Dummy or FreeForm backends in such a way that this other functionality could also be tested?
Comment 15 Andrew Isherwood 2018-05-23 13:24:48 UTC
Hi Magnus - Thanks for looking at this. Currently, all this code does is log status changes. I can see how you might have thought that other stuff was being logged as, in addition to logging during ->status calls, we also have potential logging during a ->store call. This was to catch the case where a status was being set directly in a ->store call, e.g.

->store({ status => 'REQ' })

Which obviously wouldn't have been caught by the logger in the status method.

So, there is potential to log other "things" during the ->store call, but currently we don't. It is easily added by adding a new element to the Koha::ILLRequest::Logger $loggers class property:

	
$self->{loggers} = {
    status => sub {
        $self->log_status_change(@_);
    }
};

[...]

sub log_maybe {
    my ($self, $req, $attrs) = @_;
	
    if (defined $req && defined $attrs) {
        foreach my $key (keys %{ $attrs }) {
            if (defined($self->{loggers}->{$key})) {
                $self->{loggers}->{$key}($req, $attrs->{$key});
            }
        }
    }
}

[...]

sub log_status_change {
    my ( $self, $req, $new_status ) = @_;

    $self->set_data({
        actionname   => 'STATUS_CHANGE',
        objectnumber => $req->id,
        infos        => to_json({
            log_origin    => 'core',
            status_before => $req->{previous_status},
            status_after  => $new_status
        })
    });

    $self->log_something();
}

As you can see, currently it says "if we get a call to $request->store and the thing we're storing contains a 'status' property, log the value of it"

We also provide display templates for when it comes to displaying that stored "thing" back to the user.

I *have* added a call to the logger in the BLDSS backend whenever an API request is sent to the BLDSS status check endpoint. It's a very simple addition and can be seen here:

https://github.com/PTFS-Europe/BLDSS-backend/commit/40a4ccdce6e04293970258797d7a0c4fcb33ff32

I hope this helps :)
Comment 16 Magnus Enger 2018-05-24 09:45:44 UTC
(In reply to Andrew Isherwood from comment #15)
> Hi Magnus - Thanks for looking at this. Currently, all this code does is log
> status changes. 

Ah, gotcha! I'll sign off, then. 

If you do find the time to add logging of any changes to the metadata I'll be happy to test and sign off on it!
Comment 17 Magnus Enger 2018-05-24 09:53:42 UTC
Hm, the previous version of the patch was working as expected, but with the most recent version, when I go to "Manage request" i get an "Internal Server Error". The Plack error log says: 

Template process failed: undef error - The method logs is not covered by tests! at /home/vagrant/kohaclone/C4/Templates.pm line 122

The code around line 122 looks like this:

120     my $data;
121     binmode( STDOUT, ":utf8" );
122     $template->process( $self->filename, $vars, \$data )
123       || die "Template process failed: ", $template->error();
124     return $data;

Not quite sure if there is a problem with the patch or if i screwed up my testing environment?
Comment 18 Andrew Isherwood 2018-05-30 11:04:00 UTC
Hi Magnus. I can't replicate this, seems to work fine for me. It sounds like your Illrequest object doesn't know about the "logs" method. Try setting up the testing env again maybe?
Comment 19 Andrew Isherwood 2018-08-13 15:30:08 UTC
Created attachment 77757 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.
Comment 20 PTFS Europe Sandboxes 2018-08-15 14:44:04 UTC
Created attachment 77816 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.
Comment 21 Andrew Isherwood 2018-08-15 14:46:42 UTC
Created attachment 77817 [details] [review]
Signed-off-by: Niamh Walker <Niamh.Walker-Headon@it-tallaght.ie>
Comment 22 PTFS Europe Sandboxes 2018-08-15 14:50:09 UTC
Created attachment 77818 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.

Signed-off-by: Niamh Walker <Niamh.Walker-Headon@it-tallaght.ie>
Comment 23 PTFS Europe Sandboxes 2018-08-16 14:55:32 UTC
Created attachment 77931 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.

Signed-off-by: Niamh Walker <Niamh.Walker-Headon@it-tallaght.ie>
Comment 24 Martin Renvoize 2018-08-16 14:56:34 UTC
Just had to sort out some randomness with our sandboxes.. that final patch actually includes the signoff line this time..
Comment 25 Andrew Isherwood 2018-10-02 13:58:26 UTC
Created attachment 79822 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.
Comment 26 Andrew Isherwood 2018-10-02 13:58:34 UTC
Created attachment 79823 [details] [review]
Bug 20750: Add unit tests
Comment 27 Andrew Isherwood 2018-10-02 14:04:00 UTC
Created attachment 79824 [details] [review]
Bug 20750: Allow logging of arbitrary actions

This patch allows logging of arbitrary actions on request objects. A
chronological summary of these actions can then be displayed when
viewing a request.

This patch also adds logging of request status changes. Additional work
has been done on the BLDSS backend to log requests to the BLDSS request
status check API.

To test:
- Apply patch
- Ensure the Illlog logging preference is turned on
- Create an ILL request and perform actions on it that change it's
status.
- Navigate to the "Manage ILL request" screen
- Click the "Display request log" button
- Observe that a modal opens displaying a summary of the status changes.

Signed-off-by: Niamh Walker <Niamh.Walker-Headon@it-tallaght.ie>
Comment 28 Magnus Enger 2018-10-02 15:36:36 UTC
*** Bug 21461 has been marked as a duplicate of this bug. ***
Comment 29 Andrew Isherwood 2018-10-18 15:10:49 UTC
Created attachment 80860 [details] [review]
Bug 20750: (follow-up) Fix sorting of log entries

The log entries are received from C4::Log::GetLogs with their timestamps
formatted as '2018-18-10 16:09:29', this doesn't sort well. In fact, it
causes a warning in the Koha logs:

Argument "2018-10-04 15:48:15" isn't numeric in numeric comparison (<=>)
at /home/koha/kohaclone/Koha/Illrequest/Logger.pm line 231

This patch converts the timestamps to be sorted into epoch dates prior
to them being compared