Page 1 of 1

Bug in Log when rotate log (6.40.1)

Posted: Thu Aug 10, 2017 5:28 pm
by chukinsun
Hi all,

I found log date bug when the router has timezone setting. My router is RouterBOARD 750G r2

Run Command (/log print)
# format of jan/01/2002 00:00:00 which shows up at unknown date/time. Using as default
# format of 00:00:00 which shows up on current day's logs
# format of jan/01 00:00:00 which shows up on previous day's logs

23:30:39 Aug/11/2017
----------------------------
/log print
08:11:55 system,info log action changed by admin
08:11:55 system,info log action changed by admin
08:11:55 script,info Clear Log
23:30:30 system,info change time Aug/11/2017 08:12:34 => Aug/11/2017 23:30:30
23:30:30 system,info system time zone settings changed by admin
23:30:37 system,info,account user admin logged in from 218.102.212.217 via telnet
23:30:39 system,info,account user admin logged out from 218.102.212.217 via telnet
----------------------------


04:30:39 Aug/12/2017 ( No update the time record to previous day)
----------------------------
/log print
08:11:55 system,info log action changed by admin
08:11:55 system,info log action changed by admin
08:11:55 script,info Clear Log
23:30:37 system,info,account user admin logged in from 218.102.212.217 via telnet
23:30:39 system,info,account user admin logged out from 218.102.212.217 via telnet
aug/12 04:30:59 system,info change time Aug/11/2017 23:31:02 => Aug/12/2017 04:30:59
aug/12 04:30:59 system,info system time zone settings changed by admin


08:31:39 Aug/12/2017 ( Correct the time record to previous day after timezone (My example +8:00)
----------------------------
/log print
aug/11 08:11:55 system,info log action changed by admin
aug/11 08:11:55 system,info log action changed by admin
aug/11 08:11:55 script,info Clear Log
aug/11 23:30:37 system,info,account user admin logged in from 218.102.212.217 via telnet
aug/11 23:30:39 system,info,account user admin logged out from 218.102.212.217 via telnet
04:30:59 system,info change time Aug/11/2017 23:31:02 => Aug/12/2017 04:30:59
04:30:59 system,info system time zone settings changed by admin
04:31:41 system,info change time Aug/12/2017 04:31:41 => Aug/12/2017 08:31:37
08:31:37 system,info system time zone settings changed by admin

Best
Sunny

Re: Bug in Log when rotate log (6.40.1)

Posted: Wed Feb 07, 2018 11:14 am
by jacauc
I too have experienced the same problem. I can confirm that this is a bug in the Firmware.

To summarize:
  • the log shows the following if it's the current day
    08:15:56
  • the log shows the following if it's the next day
    feb/08/2018 08:15:56

...But between 00:00:00 and 02:00:00 (because I'm at GMT+2), the log will still show the event as if it's the current day, even though it is already the next day.

This causes several problems for me when parsing logs, one example is the time cleanup section of the script at:
https://wiki.mikrotik.com/wiki/Monitor_ ... run_script

Is there a way this can be formally raised as a bug?
I suppose the log rotate function should either run at exactly 00:00:00 regardless of the timezone, or if an option can be given to always log events with the full time format including the date, even if the event occurred today?

Re: Bug in Log when rotate log (6.40.1)

Posted: Wed Feb 07, 2018 1:56 pm
by CZFan
...

Is there a way this can be formally raised as a bug?
...
send a mail to support@mikrotik.com

Re: Bug in Log when rotate log (6.40.1)

Posted: Fri Jul 12, 2019 10:41 am
by jacauc
This bug is still present in 6.45.1. I have reported the issue as a bug more than a year ago, how can this be escalated?

Re: Bug in Log when rotate log (6.40.1)

Posted: Fri Jul 12, 2019 11:06 am
by pe1chl
Such "clever" formats are always a nuisance. The best would be to always use the same format (and even better would be when the format is configurable so you can change it to e.g. YYYY-MM-DD HH:MM:SS.hh which would then be used for all messages also on current day)

However, I cannot reproduce your problem, maybe I understand incorrectly but my timezone is set to Europe/Amsterdam which is +01 with DST, so currently +02.
When I now do a /log print I get messages from yesterday with date and messages from today (also in the 00:00-02:00 range) without date.

Re: Bug in Log when rotate log (6.40.1)

Posted: Fri Jul 12, 2019 12:05 pm
by mkx
However, I cannot reproduce your problem, maybe I understand incorrectly but my timezone is set to Europe/Amsterdam which is +01 with DST, so currently +02.
When I now do a /log print I get messages from yesterday with date and messages from today (also in the 00:00-02:00 range) without date.
Did you try to print logs between midnight and 2 o'clock in the morning (not the timestamp of logs themselves, but time at the moment you run the /log print command)? I didn't but I suspect this is when the weird stuff happens ... and gets weirder with (time zone) distance from GMT.

Re: Bug in Log when rotate log (6.40.1)

Posted: Fri Jul 12, 2019 2:30 pm
by pe1chl
No, I only tried to print it after that time window had passed, as I understood from the report that it happens then as well. Maybe I misunderstood.
I will try to remember to print the log at 00:15 or so. I am not going to fiddle with the router time for this, also because I don't consider it a problem unless it happens in normal operation.
(i.e. I don't consider it a problem when weird things happen after jerking the time around)