Log File Dates & Times seem to be incorrect

I am trying to track new log entries. I have a script that works except around midnight.

Overarching Issue:
Ideally log entries would have Date Time written consistently as YYYY-MM-DD HH:M:SS. I cannot understand why it is done in a way that is not machine readable (and in US format too). Is there a way Mikrotik could have a setting that allowed the machine readable format in logs?

Specific Issue:
This is the log file produced at 01:05:00 with most entries removed. You can see the entries for sep/22 being printed with only the time and the sep/23 (Today) with the date and time. That is not correct.

# sep/23/2018  1: 5: 0 by RouterOS 6.43.2
# software id = 
#
sep/21 18:16:29 system,info router rebooted 
.
.
sep/21 23:38:43 script,info [LogMonitorScript] Run 
sep/21 23:42:29 script,info Duplicate SMTP Address 
00:06:00 system,info changed scheduled script settings by admin 
00:06:00 script,info [LOGMON] New logs found, send email 
.
.
23:38:44 script,info [LogMonitorScript] Run 
23:42:29 script,info Duplicate SMTP Address 
sep/23 00:06:00 system,info changed scheduled script settings by admin 
sep/23 00:06:00 script,info [LOGMON] New logs found, send email 
sep/23 00:08:44 script,info [LogMonitorScript] Run

My clock settings are

 /system clock> print 
                  time: 17:12:22
                  date: sep/23/2018
  time-zone-autodetect: no
        time-zone-name: Europe/Paris
            gmt-offset: +02:00
            dst-active: yes

Anyone know why this might be?

Charles

Regarding lack of date part: it’s how /log print formats it. If log is written to disk and you fetch log file to some PC, you can open it in text editor. There log entries all have full date and time.

Other than that, I would like to see date formatting in neutral way as well … e.g. according to ISO8601 standard. Among other things makes sorting according to timestamp a trivial task.

Mkx

I’ve never seen your first point. When you access the log programmatically, the datetimes come in the 3 flavours.

+1 for your second point.

Charles

Why do you not send your log entry directly to a server using Syslog receiver?
Should be one step less, instead of sending saved logs.

OP is dealing with logs directly on RB itself. And I was just saying that mangled timestamps (current day logs shown without date part) are the way in which /log print displays (and was later corrected by OP that it’s the way logs are presented programatically) them while they have date part stored (which is understandable or else date part could not be shown for older entries as well) … and I used the disk-stored logs just as an illustration.

Any views on why the log is so weird around midnight?

It looks like the internal date processor doesn’t work. Could it be to do with the time zone?

The log file produced at 02:05:00 behaves properly.

Charles

Does anyone from MikroTik have anything to say about this? It looks to me like a software error.

Charles

Without a doubt there is a bug in adding a date to the today LOG row in [/log print] procedure. The problem is with correct verification of the current date taking into account time-zone by PRINT proc. and occur between 00:00:00 and time in which current hour is equal gmt-offset (when in plus).

Print command does not take into consideration the [gmt-offset] parameter !

Maybe [time-zone-autodetect] should be set to [yes] ???


As in [Manual: System / Log]:
"If logs are printed at the same date when log entry was added, then only time will be shown. In example above you can see that second message was added on sep/15 current year (year is not added) and the last message was added today so only the time is displayed. "


Above is unworthy with the actual action of the [/log print] or [/log find] function!

… and probably will never be repaired!

BR

I can confirm that “/log print” produces wrong timestamps after midnight. For a few hours it swaps the date format of today’s and yesterday’s log entries.
Very serious (script breaking) bug.

Here is part of the output of “/log print” on sep/09 01:14:00

sep/07 23:41:02 script,info test1 - sept 07
sep/07 23:43:38 script,info test2 - sept 07
23:55:51 script,info test1 - sept 08
23:55:51 script,info test2 - sept 08
sep/09 00:00:59 script,info test1 - sept 09
sep/09 00:01:13 script,info test2 - sept 09

This was produced using GTM +2.