Bug 13413 - Koha::Log - an attempt to have sane logging in Koha
Summary: Koha::Log - an attempt to have sane logging in Koha
Status: RESOLVED DUPLICATE of bug 14167
Alias: None
Product: Koha
Classification: Unclassified
Component: Architecture, internals, and plumbing (show other bugs)
Version: master
Hardware: All All
: P5 - low enhancement (vote)
Assignee: Srdjan Jankovic
QA Contact: Testopia
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-12-09 07:48 UTC by Srdjan Jankovic
Modified: 2015-07-21 14:58 UTC (History)
5 users (show)

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


Attachments
bug_13413: Koha::Log - logging for Koha (12.33 KB, patch)
2014-12-09 07:56 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
bug_13413: use Koha::Log with syslog sink instead of syslog directly in Sipserver.pm (7.30 KB, patch)
2014-12-09 07:57 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
bug_13413: Koha::Log in longoverdue.pl (4.26 KB, patch)
2014-12-09 07:57 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
bug_13413: Koha::Log - logging for Koha (13.05 KB, patch)
2015-03-02 01:46 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
bug_13413: use Koha::Log with syslog sink instead of syslog directly in Sipserver.pm (7.33 KB, patch)
2015-03-02 01:46 UTC, Srdjan Jankovic
Details | Diff | Splinter Review
bug_13413: Koha::Log in longoverdue.pl (4.26 KB, patch)
2015-03-02 01:46 UTC, Srdjan Jankovic
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Srdjan Jankovic 2014-12-09 07:48:28 UTC
Koha is painfully lacking logging infrastructure. This is an attempt to retrofit one.

It is based on Log::Contextual rather than Log::Log4Perl for the sake of simplicity and efficiency.

This is a discussion bite.
Comment 1 Srdjan Jankovic 2014-12-09 07:56:00 UTC Comment hidden (obsolete)
Comment 2 Srdjan Jankovic 2014-12-09 07:57:23 UTC Comment hidden (obsolete)
Comment 3 Srdjan Jankovic 2014-12-09 07:57:26 UTC Comment hidden (obsolete)
Comment 4 Srdjan Jankovic 2014-12-09 07:58:37 UTC
There are two patches to give an example how to use Koha::Log
Comment 5 Martin Renvoize 2014-12-30 22:39:46 UTC
Agreed we need logging, and I'm fairly happy with the implimentation here..

However, I'd like some clear comparisons drawn to the work corried out in bug 8190 and how this patch may or may not solve the issues raised there.

I don't want this bug to end up again in a long 'In Discussion' dead end, but it would be good to know why you feel this is a better aproach so we can sell it to the community as a whole :)

Thanks for the work so far Srdjan
Comment 6 Srdjan Jankovic 2014-12-31 05:14:58 UTC
* For some reason when I started this work, I did not see bug 8190 when I searched. Horrible omission, no excuses.

* bug 8190 is a bit wider, and this replaces only one part of it (the logging module itself). If this is chosen, bug 8190 can easily be reworked to use this logger instead of its own implementation.

Now comparison:

* Log::LogLite seems to be limited to logging to a file only. To me it is a serious limitation, so if we wanted to extend it to support multiple sinks, we'd need to roll our sleeves. Nothing bad in that, but still. An example would be logging to the standard sink (a file or syslog) and sending error emails, eg "log me at info level, but email me errors".

* What really attracted me to Log::Contextual was the use of code blocks to log, so complex debugging can be left in without any performance penalty (as stated in the pod). Although some may argue it is confusing.

* There are some fancy stuff one could do (temp logger etc), but that should not be taken in account when making decision, basic stuff is more important.

I suggest some people go over this implementation of Koha::Log, and bug 8190 implementation of Koha::Utils::Logger, and decide which one is a better fit.

There are also other interesting points for discussion, but no point bringing those up before we decide if tis is a go or no go. In that respect this patch is intentionally minimal, and leaves hairy issues where/how to introduce it in the web app out. Having said that, it was implemented with intention to be able to fit both in central point (Context), the individual scripts and library modules at the same time - ie some best practices should be drawn, but nothing will break if you use it in anger.

The starting point was that I needed a cron job logger, and I put some more effort in hope it may find wider use.
Comment 7 Martin Renvoize 2014-12-31 09:02:33 UTC
Thanks for your quick reply, and good explanation Srdjan.

I think I agree that I prefer the logging capabilities given using Log::Contextual, and love the code blocks for efficiency.

I'de love to see this as a starting point for moving towards the more expansive implementation as conceived in bug 8190.. I'm going to test a bit now.
Comment 8 Robin Sheat 2015-01-28 21:46:04 UTC
(In reply to Martin Renvoize from comment #7)
> Thanks for your quick reply, and good explanation Srdjan.
> 
> I think I agree that I prefer the logging capabilities given using
> Log::Contextual, and love the code blocks for efficiency.
> 
> I'de love to see this as a starting point for moving towards the more
> expansive implementation as conceived in bug 8190.. I'm going to test a bit
> now.

Martin, did you have any joy?
Comment 9 Jonathan Druart 2015-02-16 15:59:20 UTC
Could you provide an example of how we could use this module from others Koha modules (C4::*, Koha::*) and scripts (module/*.pl)?
Comment 10 Srdjan Jankovic 2015-02-17 00:50:37 UTC
There is a number of examples in the POD (patch 1). Also, patches 2 and 3 are supposed to be working implementations. Can you please have a look and tell me if anything needs expanding/reformulating/improving, happy to do that.
Comment 11 Srdjan Jankovic 2015-02-17 00:52:26 UTC
USAGE and ADVANCED USAGE sections in POD
Comment 12 Jonathan Druart 2015-02-19 11:26:19 UTC
Actually this patch is stuck in NSO without any test plan.
Since I really would like to see a logging module integrated into Koha, I just try to make this moving forward.

So let's test this lazily:
$ git bz apply 13413 # ok

Try to use the module:
diff --git a/C4/Context.pm b/C4/Context.pm
index c5f92ee..9a88758 100644
--- a/C4/Context.pm
+++ b/C4/Context.pm
@@ -107,6 +107,8 @@ use DateTime::TimeZone;
 use Module::Load::Conditional qw(can_load);
 use Carp;
 
+use Koha::Log qw(:log with_debug);
+
 =head1 NAME
 
 C4::Context - Maintain and manipulate the context of a Koha script
@@ -564,6 +566,7 @@ sub preference {
     }
 
     $sysprefs{lc $var} = $value;
+    log_debug{"pref $var = $value"};
     return $value;
 }
 
diff --git a/mainpage.pl b/mainpage.pl
index ab3a7ab..635a233 100755
--- a/mainpage.pl
+++ b/mainpage.pl
@@ -30,6 +30,8 @@ use C4::Suggestions qw/CountSuggestion/;
 use C4::Tags qw/get_count_by_tag_status/;
 use Koha::Borrower::Modifications;
 
+use Koha::Log qw(:log with_debug);
+
 my $query = new CGI;
 
 my ( $template, $loggedinuser, $cookie, $flags ) = get_template_and_user(
@@ -42,6 +44,8 @@ my ( $template, $loggedinuser, $cookie, $flags ) = get_template_and_user(
     }
 );
 
+log_debug{'User on the mainpage!'};
+
 my $homebranch;
 if (C4::Context->userenv) {
     $homebranch = C4::Context->userenv->{'branch'};

$ tail -f koha_logs

Go on the mainpage.
boom, module is missing
ok let's install it (no mention in the commit messages)
$ sudo apt-get install liblog-contextual-perl

Go on the mainpage, nothing in the logs.
Ha, debug no defined, let's replace with log_info
Go on the mainpage.
The messages appear in the logs \o/

So the question is: How can I configure a log level for all the application?
perldoc Koha/Log.pm mentions 3 levels: debug, info, warn. What about others?
Comment 13 Jonathan Druart 2015-02-19 11:28:16 UTC
Did you read the discussion on bug 8190? There are a lot of ideas on it.

The way to use it is:

  my $logger = C4::Context->logger();
  $logger->info("OPAC: Search for $query");

You can have a look at the tests for more information.
All the job is mainly done in the constructor (Koha::Utils::Logger->new) and the write method.
And a syspref controls the log level.
Comment 14 Srdjan Jankovic 2015-03-02 01:38:51 UTC
(In reply to Jonathan Druart from comment #13)
> Did you read the discussion on bug 8190? There are a lot of ideas on it.
> 
> The way to use it is:
> 
>   my $logger = C4::Context->logger();
>   $logger->info("OPAC: Search for $query");

Yes, and that is precisely what I find inflexible. One size fits all is offered. My approach was use it where/when you need it the way you need it. Log to file/syslog/email/wherever depending on your needs. So the answer is - you don't. Eg you configure it in the psgi script, or in a cron job. Or in a module, if you need something special.

My initial pains were SIP and some cron jobs.

I do understand that majority may prefer having it already there in context with some less flexibility, in which case we'll pick the other one and go with that.
Comment 15 Srdjan Jankovic 2015-03-02 01:46:02 UTC
Created attachment 36259 [details] [review]
bug_13413: Koha::Log - logging for Koha
Comment 16 Srdjan Jankovic 2015-03-02 01:46:13 UTC
Created attachment 36260 [details] [review]
bug_13413: use Koha::Log with syslog sink instead of syslog directly in Sipserver.pm

This way we can sift out debugs
Comment 17 Srdjan Jankovic 2015-03-02 01:46:22 UTC
Created attachment 36261 [details] [review]
bug_13413: Koha::Log in longoverdue.pl
Comment 18 Srdjan Jankovic 2015-03-02 01:48:06 UTC
> Go on the mainpage.
> boom, module is missing

Added dependancy.
Comment 19 Jonathan Druart 2015-05-26 15:44:10 UTC
Srdjan,
Did you have a look at the Kyle's try on bug 14167?
Comment 20 Martin Renvoize 2015-06-17 07:44:37 UTC
I'm in general preferring the simplicity of Bug 14167 for now. Lets go with that and get this much needed feature into Koha!
Comment 21 Tomás Cohen Arazi 2015-07-21 14:58:23 UTC

*** This bug has been marked as a duplicate of bug 14167 ***