Bug 27048 - Add timestamps to verbose output of rebuild_zebra.pl
Summary: Add timestamps to verbose output of rebuild_zebra.pl
Status: Signed Off
Alias: None
Product: Koha
Classification: Unclassified
Component: Command-line Utilities (show other bugs)
Version: master
Hardware: All All
: P5 - low enhancement (vote)
Assignee: Martin Renvoize
QA Contact: Testopia
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-11-18 09:50 UTC by Martin Renvoize
Modified: 2021-02-24 23:48 UTC (History)
6 users (show)

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


Attachments
Bug 27048: Add basic timekeeping to rebuild_zebra (2.14 KB, patch)
2020-11-18 10:37 UTC, Martin Renvoize
Details | Diff | Splinter Review
Bug 27048: Add basic timekeeping to rebuild_zebra (4.03 KB, patch)
2020-11-18 12:01 UTC, Martin Renvoize
Details | Diff | Splinter Review
Bug 27048: Add basic timekeeping to rebuild_zebra (4.08 KB, patch)
2021-01-28 11:18 UTC, David Nind
Details | Diff | Splinter Review
Bug 27048: (follow-up) Use DateTime instead of POSIX (2.27 KB, patch)
2021-02-23 12:18 UTC, Martin Renvoize
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Renvoize 2020-11-18 09:50:26 UTC
It would be helpful to have timestamps added to the verbose option of rebuild_zebra.pl to see how long the rebuild has been running.
Comment 1 Martin Renvoize 2020-11-18 10:37:26 UTC
Created attachment 113773 [details] [review]
Bug 27048: Add basic timekeeping to rebuild_zebra
Comment 2 Martin Renvoize 2020-11-18 12:01:03 UTC
Created attachment 113780 [details] [review]
Bug 27048: Add basic timekeeping to rebuild_zebra

This patch adds a start time, end time and elapsed times on the 'records
exported' lines to the verbose output of the rebuild_zebra.pl script.

Test plan
1/ Run rebuild_zebra.pl -a -b -v
2/ Note the new timestamps included on the verbose output
3/ Signoff
Comment 3 David Cook 2021-01-27 23:37:28 UTC
Comment on attachment 113780 [details] [review]
Bug 27048: Add basic timekeeping to rebuild_zebra

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

::: misc/migration_tools/rebuild_zebra.pl
@@ +848,5 @@
> +    my $now_pretty = POSIX::strftime("%H:%M:%S",localtime($now));
> +    my $elapsed_pretty = $d ? "[$d:$h:$m:$s]" : $h ? "[$h:$m:$s]" : $m ? "[$m:$s]" : "[$s]";
> +
> +    return "$now_pretty $elapsed_pretty";
> +}

Why not just use DateTime->now()->strftime("%H:%M:%S")?
Comment 4 David Nind 2021-01-28 11:18:34 UTC
Created attachment 115931 [details] [review]
Bug 27048: Add basic timekeeping to rebuild_zebra

This patch adds a start time, end time and elapsed times on the 'records
exported' lines to the verbose output of the rebuild_zebra.pl script.

Test plan
1/ Run rebuild_zebra.pl -a -b -v
2/ Note the new timestamps included on the verbose output
3/ Signoff

Signed-off-by: David Nind <david@davidnind.com>
Comment 5 Katrin Fischer 2021-02-07 12:50:14 UTC
(In reply to David Cook from comment #3)
> Comment on attachment 113780 [details] [review] [review]
> Bug 27048: Add basic timekeeping to rebuild_zebra
> 
> Review of attachment 113780 [details] [review] [review]:
> -----------------------------------------------------------------
> 
> ::: misc/migration_tools/rebuild_zebra.pl
> @@ +848,5 @@
> > +    my $now_pretty = POSIX::strftime("%H:%M:%S",localtime($now));
> > +    my $elapsed_pretty = $d ? "[$d:$h:$m:$s]" : $h ? "[$h:$m:$s]" : $m ? "[$m:$s]" : "[$s]";
> > +
> > +    return "$now_pretty $elapsed_pretty";
> > +}
> 
> Why not just use DateTime->now()->strftime("%H:%M:%S")?

Martin, can you answer David's question please?
Comment 6 Katrin Fischer 2021-02-17 20:50:29 UTC
This works well, still wondering about comment#3 - Failing QA to get attention :)
Comment 7 Martin Renvoize 2021-02-18 15:13:47 UTC
(In reply to David Cook from comment #3)
> Comment on attachment 113780 [details] [review] [review]
> Bug 27048: Add basic timekeeping to rebuild_zebra
> 
> Review of attachment 113780 [details] [review] [review]:
> -----------------------------------------------------------------
> 
> ::: misc/migration_tools/rebuild_zebra.pl
> @@ +848,5 @@
> > +    my $now_pretty = POSIX::strftime("%H:%M:%S",localtime($now));
> > +    my $elapsed_pretty = $d ? "[$d:$h:$m:$s]" : $h ? "[$h:$m:$s]" : $m ? "[$m:$s]" : "[$s]";
> > +
> > +    return "$now_pretty $elapsed_pretty";
> > +}
> 
> Why not just use DateTime->now()->strftime("%H:%M:%S")?

No major reason for using POSIX.. mostly I was avoiding more DateTime use.. but as it's a single call it's not terrible so can be swapped if needed.
Comment 8 Martin Renvoize 2021-02-23 12:09:12 UTC
I have a better answer now..

1. Because there is already president for using POSIX in the script
2. Because if we were switching to DateTime we should use dt_from_string to localise and be consistent with the rest of Koha.
3. Because DateTime::Durations don't print nicely without importing DateTime::Format::Duration which would add another dependency for a reasonably trivial functionality.
4. Because I hoped to 'keep it simple' by just working in seconds.. which it did.

I've tried to write a patch to switch to using DateTime and it ends up requiring extra dependencies, looking worse in the output and more complicated to work with :(
Comment 9 Martin Renvoize 2021-02-23 12:18:15 UTC
Created attachment 117201 [details] [review]
Bug 27048: (follow-up) Use DateTime instead of POSIX

This introduces additional dependancies and builds DateTime objects
multiple times.. I'm not sure it's worth it.
Comment 10 David Cook 2021-02-24 23:48:18 UTC
I think I must not have paid enough attention to the patch the first time around. I thought you were just adding timestamps to the loglines. I didn't realize that you were tracking elapsed time as well. 

I would do it differently but I'm not the one writing the code. I'll accept the reasons for using POSIX over DateTime, so no complaint from me.