Comment on attachment 41170 [details] [review]
[SIGNED-OFF] Bug 14597 - Reverting a batch where a record overlaid is now deleted record will fail

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

::: C4/ImportBatch.pm
@@ +813,4 @@
>  sub BatchRevertRecords {
>      my $batch_id = shift;
>  
> +    my $logger = Koha::Logger->get( { category => 'C4.ImportBatch.BatchRevertRecords' } );

Really?
We are going to create an instance of Log::Log4perl for each subroutine call?

(In reply to Jonathan Druart from comment #6)
> Comment on attachment 41170 [details] [review] [review]
> [SIGNED-OFF] Bug 14597 - Reverting a batch where a record overlaid is now
> deleted record will fail
> 
> Review of attachment 41170 [details] [review] [review]:
> -----------------------------------------------------------------
> 
> ::: C4/ImportBatch.pm
> @@ +813,4 @@
> >  sub BatchRevertRecords {
> >      my $batch_id = shift;
> >  
> > +    my $logger = Koha::Logger->get( { category => 'C4.ImportBatch.BatchRevertRecords' } );
> 
> Really?
> We are going to create an instance of Log::Log4perl for each subroutine call?

Yes, otherwise we cannot do the namespacing as far as I know. This is intrinsic with Log4Perl and not a limitation of Koha::Logger. Without namespacing we may was well stick to using warn()

IMO this is really not a good idea.
I would prefer to see this logger question moved somewhere else and let this patch continues this way without it.

(Just to say, my logger proposal allowed you to display a "caller", which permit to know where we are).

Ccing people involved in the Logger discussion to get their opinions, please see comments 6-8.

(In reply to Jonathan Druart from comment #8)
> IMO this is really not a good idea.
> I would prefer to see this logger question moved somewhere else and let this
> patch continues this way without it.
> 
> (Just to say, my logger proposal allowed you to display a "caller", which
> permit to know where we are).

I'm not sure what you mean by that. I may be out of the loop. Yes, we could dump the caller into the logs, but setting the category allows us to utilize the strengths of log4perl where we can redirect parts of the log to other files, set up email alerts, use syslog, log to a db, etc. If we don't specify our categories well then we can't take advantage of any of the features of log4perl.

I just would like to be sure that we really want to add 2 lines and instantiate a Log object per subroutine/method.
I personally don't like this idea.

Since I was kindly ask to take part in this discussion:

* Koha::Log lacks a bit in the Synopsis department, especially examples how to use it within Koha:: (object) and C4 (procedural) namespaces

* I don't mind the way it is used. If the decision was made to go with  Log::Log4perl, then this is along its lines. An alternative would be to create a log object in context, and use it. Both have pros and cons. I do like the idea of having log category per request (one logger in context) as opposed to per function (which is the case with this patch). A more complete solution would be to add a mechanism to add to category, so in this case whole request would be eg marc-import, and this particular category would be marc-import.C4.ImportBatch.BatchRevertRecords

(In reply to Srdjan Jankovic from comment #12)
> Since I was kindly ask to take part in this discussion:
> 
> * Koha::Log lacks a bit in the Synopsis department, especially examples how
> to use it within Koha:: (object) and C4 (procedural) namespaces

Have you read http://wiki.koha-community.org/wiki/Koha_Logger ? I would be happy to expand it if what I've written is not sufficient!

> * I don't mind the way it is used. If the decision was made to go with 
> Log::Log4perl, then this is along its lines. An alternative would be to
> create a log object in context, and use it. Both have pros and cons. I do
> like the idea of having log category per request (one logger in context) as
> opposed to per function (which is the case with this patch). A more complete
> solution would be to add a mechanism to add to category, so in this case
> whole request would be eg marc-import, and this particular category would be
> marc-import.C4.ImportBatch.BatchRevertRecords

I don't think that would work for log4perl for the reasons I've outlined. Basically, if we had a singleton logger instance it would have a fixed namespace per request, and we'd lose all the power log4perl gives us. If I'm misunderstanding anything please let me know!

(In reply to Jonathan Druart from comment #11)
> I just would like to be sure that we really want to add 2 lines and
> instantiate a Log object per subroutine/method.
> I personally don't like this idea.

oh yeah, that's really not ideal. I wouldn't be surprised if that were to become a significant source of slow if it ever ended up in a function that got called a lot.

(In reply to Robin Sheat from comment #14)
> (In reply to Jonathan Druart from comment #11)
> > I just would like to be sure that we really want to add 2 lines and
> > instantiate a Log object per subroutine/method.
> > I personally don't like this idea.
> 
> oh yeah, that's really not ideal. I wouldn't be surprised if that were to
> become a significant source of slow if it ever ended up in a function that
> got called a lot.

I decided to run some tests, and over 1000 runs of a script with an instantiation of the logger vs no instantiation of the logger ( with both having 'use Koha::Logger' to measure just the instantiation ), the average time cost for the logger instantiation was 0.003304 seconds.

(In reply to Kyle M Hall from comment #16)
> I decided to run some tests, and over 1000 runs of a script with an
> instantiation of the logger vs no instantiation of the logger ( with both
> having 'use Koha::Logger' to measure just the instantiation ), the average
> time cost for the logger instantiation was 0.003304 seconds.

That's 3.3 seconds of cost if it gets called 1,000 times, which isn't too far fetched inside some parts of Koha (though really, those places should be fixed, but that's neither here nor there.)

Though, running a script 1,000 times isn't a very reliable test. It'll probably have more noise than signal.

That's good enough for me! I have added a followup to make the logger package level. I will also amend my wiki guidelines to reflect the fact that subroutine/method level loggers should only be used only when specifically needed for some reason.


(In reply to Robin Sheat from comment #17)
> (In reply to Kyle M Hall from comment #16)
> > I decided to run some tests, and over 1000 runs of a script with an
> > instantiation of the logger vs no instantiation of the logger ( with both
> > having 'use Koha::Logger' to measure just the instantiation ), the average
> > time cost for the logger instantiation was 0.003304 seconds.
> 
> That's 3.3 seconds of cost if it gets called 1,000 times, which isn't too
> far fetched inside some parts of Koha (though really, those places should be
> fixed, but that's neither here nor there.)
> 
> Though, running a script 1,000 times isn't a very reliable test. It'll
> probably have more noise than signal.

There is nothing in the log file using kohadevbox, I am waiting for a patch to fix it. I have sent an email to Tomas.

(In reply to Jonathan Druart from comment #19)
> There is nothing in the log file using kohadevbox, I am waiting for a patch
> to fix it. I have sent an email to Tomas.

I do want to note that these log statements won't show up with the default log4perl config.

(In reply to Kyle M Hall from comment #20)
> (In reply to Jonathan Druart from comment #19)
> > There is nothing in the log file using kohadevbox, I am waiting for a patch
> > to fix it. I have sent an email to Tomas.
> 
> I do want to note that these log statements won't show up with the default
> log4perl config.

Because of the loglevel you mean?

> Because of the loglevel you mean?

Yes, that is correct. I should have been more specific about that!

(In reply to Kyle M Hall from comment #22)
> > Because of the loglevel you mean?
> 
> Yes, that is correct. I should have been more specific about that!

No, it's because of a bug in kohadevbox, and maybe the installer and or packages as well (file permissions, path replacement, etc.).

I have to go a little deeper into the problem.

(In reply to Jonathan Druart from comment #23)
> (In reply to Kyle M Hall from comment #22)
> > > Because of the loglevel you mean?
> > 
> > Yes, that is correct. I should have been more specific about that!
> 
> No, it's because of a bug in kohadevbox, and maybe the installer and or
> packages as well (file permissions, path replacement, etc.).
> 
> I have to go a little deeper into the problem.

Right, I thought that was probably what you meant, but I just wanted to clarify that by default these logging statements would not appear. Good luck!

Created attachment 42901 [details] [review]
Bug 14597 - Reverting a batch where a record overlaid is now deleted record will fail

If batch of records is used to overlay existing records, and one of
those records is deleted, any attempt to revert this batch will fail.

The unanimous consensus is that deleted records should stay deleted (
 https://lists.katipo.co.nz/public/koha/2015-June/043048.html ).

Test Plan:
1) Import a batch of records
2) Import the same batch again, using ISBN as a matcher for overlay
3) Find a record that overlayed a previous record and delete it
   ( the match type will be "match applied" and there will be a link in
     "match details" )
4) Attempt to revert the second batch ( that overlayed the first )
5) The progress will stop at some point and never complete
6) Apply this patch
7) Attempt to revert the second batch again
8) This time it should succeed!

Signed-off-by: Do, Tam T <tdo@albright.edu>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Created attachment 42902 [details] [review]
Bug 14597 [QA Followup] - Make Logger package level

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>

Koha::Logger should log in the regular log files if the paths are not correctly set (does not exist, no permission to write, etc.).
But it's out of the scope of this bug report.

Patch pushed to master.

Thanks Kyle!