Bug 27291 - Change datetime format in Zebra logs
Summary: Change datetime format in Zebra logs
Status: RESOLVED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Transaction logs (show other bugs)
Version: Main
Hardware: All All
: P5 - low enhancement (vote)
Assignee: David Cook
QA Contact: Testopia
URL:
Keywords:
Depends on:
Blocks: 36191
  Show dependency treegraph
 
Reported: 2020-12-21 23:22 UTC by David Cook
Modified: 2024-07-04 18:38 UTC (History)
5 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Documentation contact:
Documentation submission:
Text to go in the release notes:
This enhancement changes the Zebra output log time format from the default "hh:mm:ss-DD/MM" to the more standard ISO 8601 "%FT%T". This makes the logs easier to read for both humans and machines. One benefit includes easy searching and sorting.
Version(s) released in:
24.05.00


Attachments
Bug 27291: Reformat Zebra output logs (1.79 KB, patch)
2020-12-22 00:23 UTC, David Cook
Details | Diff | Splinter Review
Bug 27291: Reformat Zebra output logs (1.83 KB, patch)
2024-01-01 22:33 UTC, David Nind
Details | Diff | Splinter Review
Bug 27291: Reformat Zebra output logs (1.91 KB, patch)
2024-01-12 10:35 UTC, Jonathan Druart
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description David Cook 2020-12-21 23:22:39 UTC
At the moment, Zebra logs using a dateformat of "hh:mm:ss-DD/MM". For example, "23:16:22-21/12".

I propose that we change it to use the dateformat of "%F %T" or "%FT%T". For example, "2020-12-21 23:16:41" or "2020-12-21T23:21:19"

It can be done by adding the following option to zebrasrv: -m "%F %T" or -m "%FT%T"

While this option doesn't obviously appear in "man zebrasrv", it does appear in "man yaz-ztest" and the manpage for zebrasrv says that zebrasrv has the same options as "yaz-ztest".
Comment 1 David Cook 2020-12-21 23:24:11 UTC
One of the reasons for changing the dateformat is to improve log file monitoring of Zebra.
Comment 2 David Cook 2020-12-22 00:23:34 UTC
Created attachment 114581 [details] [review]
Bug 27291: Reformat Zebra output logs

This patch changes the Zebra output log time format from
the default "hh:mm:ss-DD/MM" to the more standard ISO 8601
"%FT%T".

This change makes the logs easier to read for both
humans and machines. One benefit includes easy searching
and sorting.

Test plan:

1. cp debian/scripts/koha-zebra /usr/sbin/koha-zebra
2. koha-zebra --stop kohadev
3. koha-zebra --start kohadev
4. ps -efww | grep "zebrasrv"
5. Note "-m %FT%T" in the grep output
6. tail -f /var/log/koha/kohadev/zebra-output.log
7. Run a few searches like http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=ccl%3Dargawarga%3D1 or http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=e
8. Note that the timestamp in the Zebra log is formatted "2020-12-22T00:13:42" instead of like "00:13:42-22/12"
Comment 3 David Cook 2020-12-22 01:13:11 UTC
Actually going to switch the component from "Searching - Zebra" to "Packaging" as that might be more accurate...
Comment 4 Owen Leonard 2023-01-18 12:56:20 UTC
Does this require that the Zebra log be enabled somehow? zebra-output.log is empty.
Comment 5 David Cook 2023-01-22 23:23:07 UTC
(In reply to Owen Leonard from comment #4)
> Does this require that the Zebra log be enabled somehow? zebra-output.log is
> empty.

Ah possibly! If you update the koha-conf.xml with the following:

<zebra_loglevels>none,fatal,warn,request</zebra_loglevels>

Then restart memcached and plack, then you should get some output.
Comment 6 Lucas Gass 2023-11-08 20:59:12 UTC
I applied the patch, updated my koha-conf, and restarted everything. I still see timestamps like this:


20:57:34-08/11 


Quite possible I am doing something wrong.
Comment 7 David Cook 2023-11-08 23:15:38 UTC
(In reply to Lucas Gass from comment #6)
> I applied the patch, updated my koha-conf, and restarted everything. I still
> see timestamps like this:
> 
> 
> 20:57:34-08/11 
> 
> 
> Quite possible I am doing something wrong.

That's interesting. I applied the patch, updated my koha-conf.xml, and otherwise followed the test plan, and I'm seeing this:

2023-11-08T23:14:52 zebrasrv(1) [request] Auth idPass kohauser -
2023-11-08T23:14:52 zebrasrv(1) [request] Init OK - ID:81 Name:ZOOM-C/YAZ Version:5.30.3 2af59bc45cf4508d5c84f350ee99804c4354b3b3
2023-11-08T23:14:52 zebrasrv(1) [request] Search biblios OK 393 1 1+0 RPN @attrset Bib-1 @attr 1=1016 @attr 4=6 @attr 5=1 @attr 2=102 e
2023-11-08T23:14:52 zebrasrv(1) [request] Present OK -   1 1+1
Comment 8 David Cook 2023-11-08 23:16:32 UTC
Revised Test plan:

0. vi /etc/koha/sites/kohadev/koha-conf.xml
Update zebra_loglevels to the following:
<zebra_loglevels>none,fatal,warn,request</zebra_loglevels>
1. cp debian/scripts/koha-zebra /usr/sbin/koha-zebra
2. koha-zebra --stop kohadev
3. koha-zebra --start kohadev
4. ps -efww | grep "zebrasrv"
5. Note "-m %FT%T" in the grep output
6. tail -f /var/log/koha/kohadev/zebra-output.log
7. Run a few searches like http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=ccl%3Dargawarga%3D1 or http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=e
8. Note that the timestamp in the Zebra log is formatted "2020-12-22T00:13:42" instead of like "00:13:42-22/12"
Comment 9 David Nind 2024-01-01 22:33:10 UTC
Created attachment 160389 [details] [review]
Bug 27291: Reformat Zebra output logs

This patch changes the Zebra output log time format from
the default "hh:mm:ss-DD/MM" to the more standard ISO 8601
"%FT%T".

This change makes the logs easier to read for both
humans and machines. One benefit includes easy searching
and sorting.

Test plan:

1. cp debian/scripts/koha-zebra /usr/sbin/koha-zebra
2. koha-zebra --stop kohadev
3. koha-zebra --start kohadev
4. ps -efww | grep "zebrasrv"
5. Note "-m %FT%T" in the grep output
6. tail -f /var/log/koha/kohadev/zebra-output.log
7. Run a few searches like http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=ccl%3Dargawarga%3D1 or http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=e
8. Note that the timestamp in the Zebra log is formatted "2020-12-22T00:13:42" instead of like "00:13:42-22/12"

Signed-off-by: David Nind <david@davidnind.com>
Comment 10 David Nind 2024-01-01 22:36:47 UTC
Testing notes (using KTD):

1. Note the amended test plan in comment #8 (particularly to change the log level)
2. Koha package commands: use sudo in front or access shell as ktd --root --shell
Comment 11 Jonathan Druart 2024-01-12 10:35:54 UTC
Created attachment 160919 [details] [review]
Bug 27291: Reformat Zebra output logs

This patch changes the Zebra output log time format from
the default "hh:mm:ss-DD/MM" to the more standard ISO 8601
"%FT%T".

This change makes the logs easier to read for both
humans and machines. One benefit includes easy searching
and sorting.

Test plan:

1. cp debian/scripts/koha-zebra /usr/sbin/koha-zebra
2. koha-zebra --stop kohadev
3. koha-zebra --start kohadev
4. ps -efww | grep "zebrasrv"
5. Note "-m %FT%T" in the grep output
6. tail -f /var/log/koha/kohadev/zebra-output.log
7. Run a few searches like http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=ccl%3Dargawarga%3D1 or http://localhost:8081/cgi-bin/koha/catalogue/search.pl?q=e
8. Note that the timestamp in the Zebra log is formatted "2020-12-22T00:13:42" instead of like "00:13:42-22/12"

Signed-off-by: David Nind <david@davidnind.com>

Signed-off-by: Jonathan Druart <jonathan.druart@bugs.koha-community.org>
Comment 12 Katrin Fischer 2024-03-22 09:37:03 UTC
Pushed for 24.05!

Well done everyone, thank you!
Comment 13 Fridolin Somers 2024-05-22 13:57:33 UTC
Not backported to 23.11.x
Comment 14 David Cook 2024-05-26 23:39:46 UTC
I'd marked this one as Packaging as it only affects packaged Koha, but all good
Comment 15 Katrin Fischer 2024-05-27 07:08:44 UTC
(In reply to David Cook from comment #14)
> I'd marked this one as Packaging as it only affects packaged Koha, but all
> good

Hm, can you explain why that is? Why does the loggging for tarball Koha differ?
Comment 16 David Cook 2024-05-28 00:05:21 UTC
(In reply to Katrin Fischer from comment #15)
> (In reply to David Cook from comment #14)
> > I'd marked this one as Packaging as it only affects packaged Koha, but all
> > good
> 
> Hm, can you explain why that is? Why does the loggging for tarball Koha
> differ?

When you install Koha from a tarball, you have to set up your own Zebra service and the logging format is based off a command line parameter. 

I suppose we could also update ./misc/bin/koha-zebra-ctl.sh although we haven't in the past when we added the "-k $max_record_size" parameter.
Comment 17 Katrin Fischer 2024-05-28 07:24:03 UTC
Thx for the explanation, been a while since I did a tarball one :)
Comment 18 David Cook 2024-05-29 02:35:54 UTC
(In reply to Katrin Fischer from comment #17)
> Thx for the explanation, been a while since I did a tarball one :)

Me too! Other than for testing the build process hehe. I do love packages :3
Comment 19 Caroline Cyr La Rose 2024-07-04 18:38:07 UTC
I don't see anything that needs to be added or edited in the end user manual.