Bug 13889 - Add information about cron jobs to system log
Summary: Add information about cron jobs to system log
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Staff interface (show other bugs)
Version: Main
Hardware: All All
: P5 - low enhancement (vote)
Assignee: Marc Véron
QA Contact: Testopia
URL:
Keywords:
Depends on: 6911
Blocks:
  Show dependency treegraph
 
Reported: 2015-03-22 12:47 UTC by Marc Véron
Modified: 2016-12-05 21:22 UTC (History)
7 users (show)

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


Attachments
Bug 13889 - Add information about cron jobs to system log (19.23 KB, patch)
2015-03-22 13:04 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (19.23 KB, patch)
2015-03-27 14:49 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (19.44 KB, patch)
2015-04-11 15:02 UTC, Marc Véron
Details | Diff | Splinter Review
[Follow-up]Bug 13889 Add syspref to sysprefs.sql and updatedatabase.pl (2.19 KB, patch)
2015-04-12 14:03 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (21.40 KB, patch)
2015-04-13 06:52 UTC, Frédéric Demians
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (21.03 KB, patch)
2015-04-18 09:27 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (21.68 KB, patch)
2015-04-20 12:25 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (21.10 KB, patch)
2015-04-21 05:50 UTC, Mark Tompsett
Details | Diff | Splinter Review
Bug 13889: Added Test Coverage (1.73 KB, patch)
2015-04-21 05:50 UTC, Mark Tompsett
Details | Diff | Splinter Review
Bug 13889 - Add information about cron jobs to system log (21.15 KB, patch)
2015-04-21 05:52 UTC, Mark Tompsett
Details | Diff | Splinter Review
Bug 13889: Added Test Coverage (1.73 KB, patch)
2015-04-21 05:52 UTC, Mark Tompsett
Details | Diff | Splinter Review
[Signed-off] Bug 13889: Added Test Coverage (1.88 KB, patch)
2015-04-21 09:38 UTC, Marc Véron
Details | Diff | Splinter Review
Bug 13889: Log with parameters (1.58 KB, patch)
2015-04-21 11:22 UTC, Jonathan Druart
Details | Diff | Splinter Review
[Follow-up] Provide parameter $infos in cronlogaction() (Alternative for patch Bug 13889: Log with parameters) (1.46 KB, patch)
2015-04-21 15:27 UTC, Marc Véron
Details | Diff | Splinter Review
[PASSED QA] Bug 13889 - Add information about cron jobs to system log (21.24 KB, patch)
2015-04-23 11:52 UTC, Kyle M Hall
Details | Diff | Splinter Review
[PASSED QA] Bug 13889: Added Test Coverage (1.93 KB, patch)
2015-04-23 11:53 UTC, Kyle M Hall
Details | Diff | Splinter Review
[PASSED QA] Provide parameter $infos in cronlogaction() (Alternative for patch Bug 13889: Log with parameters) (1.51 KB, patch)
2015-04-23 11:53 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 13889 [QA Followup] - Supress warning, set object column to undef instead of 0 (907 bytes, patch)
2015-04-23 11:53 UTC, Kyle M Hall
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Marc Véron 2015-03-22 12:47:23 UTC
The system log should contain information about cron jobs performed and make it viewable under Home > Tools > Logs ("Browse system logs")
Comment 1 Marc Véron 2015-03-22 13:04:55 UTC Comment hidden (obsolete)
Comment 2 Marc Véron 2015-03-27 14:49:02 UTC Comment hidden (obsolete)
Comment 3 Frédéric Demians 2015-04-11 10:02:22 UTC
I wasn't able to apply this patch on master:

fatal: sha1 information is lacking or useless (koha-tmpl/intranet-tmpl/prog/en/modules/tools/viewlog.tt).
Comment 4 Marc Véron 2015-04-11 15:02:29 UTC Comment hidden (obsolete)
Comment 5 Marc Véron 2015-04-11 15:13:25 UTC
(In reply to Frédéric Demians from comment #3)
> I wasn't able to apply this patch on master:
> 
> fatal: sha1 information is lacking or useless
> (koha-tmpl/intranet-tmpl/prog/en/modules/tools/viewlog.tt).

Hi Frédéric, thanks for testing.

The patch depends on Bug 6911 (has changes to viewlog.tt), my patch should apply on top of this bug.
I rebased 2 more conflicts after applying 6911.
Re-tested applying, works for me on current master.
Comment 6 Frédéric Demians 2015-04-12 10:06:00 UTC
(In reply to Marc Véron from comment #5)

> The patch depends on Bug 6911 (has changes to viewlog.tt), my patch should
> apply on top of this bug.
> I rebased 2 more conflicts after applying 6911.
> Re-tested applying, works for me on current master.

Works for me also.

Your patch add a new syspref in .pref file. I think you still have to add it in the DB also:

http://wiki.koha-community.org/wiki/System_Preferences#Adding_a_new_system_preference
Comment 7 Marc Véron 2015-04-12 14:03:12 UTC Comment hidden (obsolete)
Comment 8 Frédéric Demians 2015-04-13 06:52:54 UTC Comment hidden (obsolete)
Comment 9 Kyle M Hall 2015-04-17 11:08:31 UTC
The syspref CronjobLog is created, but is not used. Instead the cronjob logs are always written. I'm not sure if this is a bad thing. However, either then system preference needs to be removed, or utilized.
Comment 10 Marc Véron 2015-04-18 09:27:59 UTC Comment hidden (obsolete)
Comment 11 Mark Tompsett 2015-04-20 01:07:57 UTC
Comment on attachment 38116 [details] [review]
Bug 13889 - Add information about cron jobs to system log

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

::: installer/data/mysql/sysprefs.sql
@@ +474,5 @@
>  ('XSLTDetailsDisplay','default','','Enable XSL stylesheet control over details page display on intranet','Free'),
>  ('XSLTResultsDisplay','default','','Enable XSL stylesheet control over results page display on intranet','Free'),
>  ('z3950AuthorAuthFields','701,702,700',NULL,'Define the MARC biblio fields for Personal Name Authorities to fill biblio.author','free'),
> +('z3950NormalizeAuthor','0','','If ON, Personal Name Authorities will replace authors in biblio.author','YesNo'),
> +('CronjobLog','0',NULL,'If ON, log information from cron jobs.','YesNo')

This should be placed alphabetically.
Comment 12 Mark Tompsett 2015-04-20 01:11:53 UTC
Comment on attachment 38116 [details] [review]
Bug 13889 - Add information about cron jobs to system log

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

::: installer/data/mysql/updatedatabase.pl
@@ +10039,5 @@
> +if ( CheckVersion($DBversion) ) {
> +    $dbh->do("INSERT IGNORE INTO `systempreferences` (variable,value,explanation,options,type) VALUES ('CronjobLog','0',NULL,'If ON, log information from cron jobs.','YesNo');");
> +    print "Upgrade to $DBversion done (Add CronjobLog syspref)\n";
> +    SetVersion ($DBversion);
> +}

This new. Why not do the new atomic update way?
http://wiki.koha-community.org/wiki/Database_updates
Comment 13 Mark Tompsett 2015-04-20 01:17:48 UTC
Koha QA tools fails related to my comment #11.
And a tab character on line 37 of C4/Log.pm
Comment 14 Marc Véron 2015-04-20 12:25:57 UTC Comment hidden (obsolete)
Comment 15 Marc Véron 2015-04-20 12:30:05 UTC
Reset to 'Needs Signoff'.
Comment 16 Mark Tompsett 2015-04-21 05:50:53 UTC Comment hidden (obsolete)
Comment 17 Mark Tompsett 2015-04-21 05:50:58 UTC Comment hidden (obsolete)
Comment 18 Mark Tompsett 2015-04-21 05:52:19 UTC Comment hidden (obsolete)
Comment 19 Mark Tompsett 2015-04-21 05:52:26 UTC Comment hidden (obsolete)
Comment 20 Mark Tompsett 2015-04-21 05:57:21 UTC
Leaving as 'Needs Signoff', because my test coverage addition can't be signed off by me.

Also, I ran the purge suggestions cronjob to test the logging. I did not run all the scripts, though I did look at all of them. They were all the same change: use C4::Log, and trigger a cronlogaction() after a successful start.
Comment 21 Marc Véron 2015-04-21 09:38:22 UTC Comment hidden (obsolete)
Comment 22 Jonathan Druart 2015-04-21 11:22:10 UTC Comment hidden (obsolete)
Comment 23 Jonathan Druart 2015-04-21 11:22:50 UTC
(In reply to Jonathan Druart from comment #22)
> Created attachment 38239 [details] [review] [review]
> Bug 13889: Log with parameters

Marc, What do you think of this patch?
Comment 24 Mark Tompsett 2015-04-21 13:47:06 UTC
(In reply to Jonathan Druart from comment #23)
> (In reply to Jonathan Druart from comment #22)
> > Created attachment 38239 [details] [review] [review] [review]
> > Bug 13889: Log with parameters
> 
> Marc, What do you think of this patch?

-- I know I'm not Marc Véron, but I thought I'd chime in my like of that kind of tweak with the parameters. However, you also moved it before a successful start. If we have it before a successful start, then where will we record the difference between the successful start or failure to start? A failure to log when the cronjoblog is on, is an implied failure to start. And if we distinguish between those two, why not a successful run as well? There's no status column. Just some thoughts.
Comment 25 Marc Véron 2015-04-21 14:03:50 UTC
(In reply to Jonathan Druart from comment #23)
> (In reply to Jonathan Druart from comment #22)
> > Created attachment 38239 [details] [review] [review] [review]
> > Bug 13889: Log with parameters
> 
> Marc, What do you think of this patch?

Jonatan, I like the idea. I was thinking about adding some more detailed information to the action log before and I planned to expand it after this patch set is pushed. 

First consideration:

With the patch, I have the following problem:

Call of cronlogaction() without param does not display the path:
2015-04-21 15:24:09 	0 	Cron jobs 	Run 	0

Call of cronlogaction(join ' ', $0, @ARGV) displays the path and the params:
2015-04-21 15:24:09 	0 	Cron jobs 	Run 	0 	misc/cronjobs/overdue_notices.pl -n -csv 

IMO cronlogaction() (without param) should behave as before.

Second consideration: 

I think it would be better tho have a string as param and to prepend it with caller(0))[1] or whatever it needs to display the script's name. 
(That is what I was planning as a next step.)

With a string param it is up to the logscript's author to decide what to communicate in the logs (in a human readable form), e.g. not only the params but their defaults as well if no params are passed.

That brings me to the third consideration: 

The original idea is that the log is written after all of the preconditions. If the script dies before doing anything "real", no log is written. Otherwise we have an entry in the logs for a cronjob that was called but did not do anything, and users think that everything is OK.

With the string param mentioned above the author of the log file then can use logging for more sophisticated things (if necessary), e.g.

- cronlogaction("start")
- do the preconditions and log some information if it dies: cronlogaction("fail: ..reason...)"
- cronlogaction("execute with: ...intersting params / defaults...")
- cronlogaction("success") or cronlogaction("success: ...interesting results...")

As a minimum, cronlogaction should be called as soon the script does the real work (that's what my patches to the cronjobs do at the moment), in the sense of "Hi, I was here and did something"

So I propose to add the string parameter and, for this first step, leave the calls in the cron scripts as is.

What do you think?
Comment 26 Marc Véron 2015-04-21 15:27:16 UTC Comment hidden (obsolete)
Comment 27 Kyle M Hall 2015-04-23 11:52:57 UTC
Created attachment 38406 [details] [review]
[PASSED QA] Bug 13889 - Add information about cron jobs to system log

This patch adds information about cron jobs performed and make it viewable
under Home > Tools > Logs ("Browse system logs")

To test:

Apply patch
- Got to system preferences and set 'CronjobLog' to:  [Log] information from
  cron jobs.
- Run some cron jobs
- Go to Home > Tools > Logs
- Verify that you have a selection 'Cron jobs' in drop-down 'Module'. Select it
  with Action "All" and Submit.
- Output should show Date/time and info about Cron jobs

Rebased to work on top of Bug 6911 (conflict in viewlog.tt)  /MV

Rebased after applying patch for Bug 6911 /MV
Conflicts resolved:
misc/cronjobs/overdue_notices.pl
misc/cronjobs/cleanup_database.pl

Signed-off-by: Frederic Demians <f.demians@tamil.fr>
  - Merge both patches, and fix updatedatabase.pl
  - Works as described. Provide intersting feedback from cronjob scripts.

--
Modified version taking in account syspref CronJobLog. Handling simplified by introducing a convenience sub cronlogaction in C4/Log.pm /MV
Amended to take in account comments #11, #12, #13 /MV

http://bugs.koha-community.org/show_bug.cgi?id=13899

Signed-off-by: Mark Tompsett <mtompset@hotmail.com>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 28 Kyle M Hall 2015-04-23 11:53:19 UTC
Created attachment 38407 [details] [review]
[PASSED QA] Bug 13889: Added Test Coverage

Previous commit was lacking test coverage of new function.

TEST PLAN
---------
1) Apply all the patches
2) prove -v t/db_dependent/Log.t
   -- should be success.
3) koha qa test tools

Signed-off-by: Marc Véron <veron@veron.ch>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 29 Kyle M Hall 2015-04-23 11:53:22 UTC
Created attachment 38408 [details] [review]
[PASSED QA] Provide parameter $infos in cronlogaction() (Alternative for patch Bug 13889: Log with parameters)

To test:

- Apply patches interactive and skip following patch:  Bug 13889: Log with parameters
- Tweak a cron job in order to call cronlogaction twice, one with a param at the beginning of the cron ob, e.g.
cronlogaction("This is my message") and one without param.
- Run this cron job.
Result: You should have two entries in the log, one with and one without additional information after the path and name of the calling script.

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 30 Kyle M Hall 2015-04-23 11:53:25 UTC
Created attachment 38409 [details] [review]
Bug 13889 [QA Followup] - Supress warning, set object column to undef instead of 0
Comment 31 Jonathan Druart 2015-04-23 12:07:51 UTC
Kyle, Have you seen the discussion before? What's your opinion on it?
See from comment 22
Comment 32 Tomás Cohen Arazi 2015-05-04 14:46:54 UTC
Patches pushed to master.

Good job Marc!