Logging prefix is a mess SUP-105353 SUP-144261. Waiting for MT to support RFC 5424

Jotne · August 6, 2017, 5:49pm

I do log packet from my mikrotik’s to Splunk.
This works nice, except I have problem to categorize package.

Here is a list of prefix I have found:

certificate,debug
certificate,info
dhcp,critical,error
dhcp,debug
dhcp,debug,packet
dhcp,debug,state
dhcp,info
dhcp,warning
dns
dns,packet
e-mail,debug
firewall,info
interface,info
ipsec
ipsec,debug
ipsec,debug,packet
ipsec,error
ipsec,info
l2tp,debug
l2tp,debug,packet
l2tp,info
l2tp,ppp,debug
l2tp,ppp,debug,packet
l2tp,ppp,error
l2tp,ppp,info
l2tp,ppp,info,account
ntp,debug
ntp,debug,packet
pptp,debug
pptp,debug,packet
pptp,info
pptp,ppp,debug
pptp,ppp,debug,packet
pptp,ppp,error
pptp,ppp,info
pptp,ppp,info,account
radvd,debug
route,debug
route,debug,calc
route,debug,event
script,error
snmp
snmp,debug
ssh,debug
ssh,debug,packet
ssh,info
sstp,packet
system,e-mail,error
system,error,critical
system,info
system,info,account
upnp

It looks like its on format:
module,severity,info, eks ssh,debug,packet
But that is only half true.
What about:
system,error,critical is that module,severity,severity?
system,e-mail,error module,module,severity?
ipsec here is severity missing
pptp,ppp,info,account module,module,severity,info?

Why no just clean this up to only use module, severity, info.
Eks:
e-mail,error, blabla other info
On all message use severity.

E-mail should be its own module, not listed under system.

Hope some one can clean this up. It would make Splunk application much more easy.

Jo

Jotne · July 13, 2018, 11:50am

Still nothing has happen to this.

Jotne · April 18, 2019, 7:04am

I am still waiting for this to be fixed (cleaned up)
Should not be to hard??
If it can not be done whit 6.x, add it to the 7.x version of ros

Jotne · June 17, 2020, 2:34pm

I can see that v7 beta has not fixed anything regarding log format.

neutronlaser · September 11, 2020, 2:19am

I don’t think anyone cares.

jarda · September 11, 2020, 4:29am

Seems so. But the idea is not bad, I like it.

Jotne · September 11, 2020, 8:16am

When using external logging tools like Splunk to analyse logs, this old and messy format gives a lot of extra work.
I have sent this request two times to MikroTik so they know about it.

pe1chl · January 13, 2021, 9:56am

I have filed a feature request some time ago to allow more control over the logging.
Of course the best would be when there is much more detail about the log message in the prefix, probably even up to a unique identifier of each message.
(so you don’t have to rely on pattern matching of the message text to separate the individual error messages for the same category)
When each message has a unique category it would also be possible to suppress certain messages while showing detailed output of some category for some reason (when not using Splunk but only the internal logging handler).

Lacking that, I have proposed to add regexp matching capability to the logging topics matcher, but of course more detailed topics would be best.

Jotne · December 8, 2021, 1:00pm

Still not fixed in v7.1

infabo · June 2, 2022, 11:09am

ROS-internally they just throw all into the same bin and call it “topics”. So no distinction between module and severity.
But they seem to already separate module/severity when logging to syslog-server (see https://help.mikrotik.com/docs/display/ROS/Log).

Jotne · October 1, 2022, 8:02am

There are some small changes in 7.x but as you see in the list below, its not possible to see what severity level each type of log lines have.
Example some DNS just shows DNS. IT should be in an equal comma separated format. Example l2tp,ppp,info,account compare to l2tp,info. Severity at 3rd or 2end field??

Look at these two:
system,critical,info
system,error,critical
What critically are those messages?

Taken from 7.5 logs:

bridge,info
bridge,stp
dhcp,debug
dhcp,debug,packet
dhcp,debug,state
dhcp,info
dhcp,warning
dns
dns,error
dns,packet
dns,warning
e-mail,info
firewall,info
info
interface,info
ipsec
ipsec,error
ipsec,info
l2tp,info
l2tp,ppp,error
l2tp,ppp,info
l2tp,ppp,info,account
netwatch,info
ntp,warning
poe-out,info
route,bgp,error
route,bgp,info
route,ospf,info
route,ospf,warning
script,error
script,info
snmp
ssh,info
system,critical,info
system,error,critical
system,info
system,info,account
system,info,critical
upnp
wireguard,debug
wireless,info

Make it some like this:
Module,Severity,Type,Other

pe1chl · October 1, 2022, 9:06am

As written above, I would propose adding another identifier which is unique for the message. E.g. an 8-digit hex number. That would be last in the sequence.
This allows to suppress one particular message or to match it in a script. The number would be assigned once to each specific message and never change. Maybe the first digit of the number would indicate the severity, then some digits for the module, and the remainder the message number.

Jotne · October 1, 2022, 9:41am

I like that idea, an ID in form of a number of text.
If you look at logg message for a Cisco Router/Firewall, all message have their own ID:

%CDP_PD-4-POWER_OK
%DOT11-4-BA_FLUSH
%DOT11-6-ROAMED
%EVT-4-WRN
%HA_EM-6-LOG
%ILPOWER-7-DETECT
%LINEPROTO-5-UPDOWN
%LINK-3-UPDOWN
%LINK-5-CHANGED
%LINK-6-UPDOWN
%SW_MATM-4-MACFLAP_NOTIF
%SYS-3-HARIKARI
%SYS-5-CONFIG_I
%SYS-5-RELOAD

etc
They are in the form
Module-Severity-Type_of_message.

Some like I requested above

pe1chl · October 1, 2022, 9:50am

Yes, most professional systems have such a structure. E.g. VMS, IBM operating systems, even Microsoft Windows has error numbers.
Essential in my opinion is that the number is only an addition for programming purposes (scripting, logging in external systems, etc) and not a replacement as it is in Microsoft Windows.
(something went wrong, error code 89abcdef. which you then have to google to see what it even means. there should always be a message text)

Jotne · October 1, 2022, 9:58am

I am not very happy with the Microsoft logging part.

Yes, each message has its own ID, so that is ok, but:

XML will give large/long messages.

Standard logs: hard to see what belongs to what and they do add an message telling: “This message was genereted due to ++++”.
Same text added to same EventCode id. Just makes the message longer without giving any thing extra.

And if you install Swedish or other language on a server running Citrix or other Multi user system) the log message are mixed in English and Swedish…

Jotne · November 6, 2022, 6:31pm

The best solution to make logging great again for syslog:

Just use:

rfc 5424 (released March 2009)

There all modules are separated by correct name at correct location in the message.
Messages that belongs together have same ID
etc…

Please MT do follow standards.
https://www.rfc-editor.org/rfc/rfc5424

smyers119 · November 7, 2022, 9:13pm

mikrotik already has a checkbox to enable rfc3164 compatibility.

Jotne · November 8, 2022, 9:18am

How do you know?

Znevna · November 8, 2022, 9:26am

bsd-syslog (yes|no; Default: ) whether to use bsd-syslog as defined in RFC 3164

https://wiki.mikrotik.com/wiki/Manual:System/Log

Jotne · November 8, 2022, 4:13pm

Does no help at all. BSD logs are even worse . Look at these DHCP debug logs.

BSD logs

2022-11-08T17:06:35.639612+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Client-Id = 01-00-0C-AA-9B-EA-66
2022-11-08T17:06:35.639683+01:00 <31>Nov  8 17:06:34 OVA MikroTik: dhcp-client on bridge received ack with id 3916435468 from 10.11.10.1
2022-11-08T17:06:35.639744+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     ciaddr = 0.0.0.0
2022-11-08T17:06:35.639831+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     yiaddr = 10.11.10.141
2022-11-08T17:06:35.639884+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     siaddr = 10.11.10.1
2022-11-08T17:06:35.639956+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     chaddr = 00:0C:AA:9B:EA:66
2022-11-08T17:06:35.640060+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Subnet-Mask = 255.255.254.0
2022-11-08T17:06:35.640144+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Router = 10.11.10.1
2022-11-08T17:06:35.640210+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Domain-Server = 10.11.10.1
2022-11-08T17:06:35.640285+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     NTP-Server = 10.11.10.1
2022-11-08T17:06:35.640349+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Address-Time = 86400
2022-11-08T17:06:35.640431+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Msg-Type = ack
2022-11-08T17:06:35.640493+01:00 <31>Nov  8 17:06:34 OVA MikroTik:     Server-Id = 10.11.10.1
2022-11-08T17:06:35.640567+01:00 <30>Nov  8 17:06:34 OVA MikroTik: dhcp-client on bridge got IP address 10.11.10.141
2022-11-08T17:06:35.640631+01:00 <31>Nov  8 17:06:34 OVA MikroTik: dhcp-client on bridge entering <bound> state
2022-11-08T17:06:37.048188+01:00 <30>Nov  8 17:06:36 OVA MikroTik: user jotne logged in from 10.11.10.32 via winbox
2022-11-08T17:06:37.231730+01:00 <30>Nov  8 17:06:36 OVA MikroTik: local query: #1 upgrade.mikrotik.com. A
2022-11-08T17:06:37.260367+01:00 <30>Nov  8 17:06:36 OVA MikroTik: done query: #1 upgrade.mikrotik.com 159.148.172.226

Without BSD

2022-11-08T17:08:43.989247+01:00 <13>dhcp,debug,packet MikroTik:     Client-Id = 01-00-0C-AA-9B-EA-66
2022-11-08T17:08:43.989411+01:00 <13>dhcp,debug,packet MikroTik: dhcp-client on bridge received ack with id 1310283069 from 10.11.10.1
2022-11-08T17:08:43.989411+01:00 <13>dhcp,debug,packet MikroTik:     flags = broadcast
2022-11-08T17:08:43.989506+01:00 <13>dhcp,debug,packet MikroTik:     ciaddr = 0.0.0.0
2022-11-08T17:08:43.989571+01:00 <13>dhcp,debug,packet MikroTik:     yiaddr = 10.11.10.141
2022-11-08T17:08:43.989619+01:00 <13>dhcp,debug,packet MikroTik:     siaddr = 10.11.10.1
2022-11-08T17:08:43.989698+01:00 <13>dhcp,debug,packet MikroTik:     chaddr = 00:0C:AA:9B:EA:66
2022-11-08T17:08:43.989748+01:00 <13>dhcp,debug,packet MikroTik:     Subnet-Mask = 255.255.254.0
2022-11-08T17:08:43.989859+01:00 <13>dhcp,debug,packet MikroTik:     Router = 10.11.10.1
2022-11-08T17:08:43.990017+01:00 <13>dhcp,debug,packet MikroTik:     Domain-Server = 10.11.10.1
2022-11-08T17:08:43.990017+01:00 <13>dhcp,debug,packet MikroTik:     NTP-Server = 10.11.10.1
2022-11-08T17:08:43.990017+01:00 <13>dhcp,debug,packet MikroTik:     Address-Time = 86400
2022-11-08T17:08:43.990114+01:00 <13>dhcp,debug,packet MikroTik:     Msg-Type = ack
2022-11-08T17:08:43.990203+01:00 <13>dhcp,debug,packet MikroTik:     Server-Id = 10.11.10.1
2022-11-08T17:08:43.990315+01:00 <13>dhcp,info MikroTik: dhcp-client on bridge got IP address 10.11.10.141
2022-11-08T17:08:43.990362+01:00 <13>dhcp,debug,state MikroTik: dhcp-client on bridge entering <bound> state

As you see with BSD, you do not see what module data belongs to, but it sends the router name as extra info.
Without BSD it sends DHCP, DEBUG, PACKET

It would help allot if an ID was sent as part of the DHCP request (or other logs that are multiple lines) to make sure what belongs togeather.