Issue using S_ISODATE in python

[ryanfaircloth]

syslog-ng

Version of syslog-ng

3.38.1

Platform

linux (docker)

Steps to reproduce

using the following global

and having parsed a ts correct with msec the TS returned in the following python does not include ms

log_message['S_ISODATE'].decode("utf-8")

"timestamp": "2022-09-15T21:56:38+00:00",

Using a json template

template t_json_kafka {
    template('$(format-json --scope rfc5424 --exclude DATE --exclude LEGACY_MSGHDR --key RAWMSG --key TAGS --key MSGID --key SEQNUM --key S_ISODATE --key R_ISODATE --key S_UNIXTIME --key R_UNIXTIME --key .metadata.* --key .SDATA.* --key fields.*)');
};

Output

{
	"fields": {
		"message": "Notification: 3/17/2022 18:35:12 system-login-change severity-level:minor host-name:\"XYZ_vManage_East\" system-ip:1.1.1.3 user-name:\"mn2c\" user-id:2227"
	},
	"TAGS": [
		"wireformat:rfc",
		"wireformat:rfc3164",
		"source_identified",
		"msgtype:unstructured",
		"msg:unparsed",
		".app.app-cisco-cisco_viptela",
		".app.core-proto-3164-cisco_syslog1",
		".source.s_net_default"
	],
	"S_UNIXTIME": "1663432932.000000",
	"S_ISODATE": "2022-09-17T16:42:12.000000+00:00",
	"R_UNIXTIME": "1663432932.749567",
	"R_ISODATE": "2022-09-17T16:42:12.749567+00:00",
	"RAWMSG": "<73> Sep 17 16:42:12 SYSMGR[919]: %Viptela-desktop-53-sysmgrd-6-INFO-1400002: Notification: 3/17/2022 18:35:12 system-login-change severity-level:minor host-name:\"XYZ_vManage_East\" system-ip:1.1.1.3 user-name:\"mn2c\" user-id:2227",
	"PROGRAM": "SYSMGR",
	"PRIORITY": "alert",
	"PID": "919",
	"MESSAGE": "%Viptela-desktop-53-sysmgrd-6-INFO-1400002: Notification: 3/17/2022 18:35:12 system-login-change severity-level:minor host-name:\"XYZ_vManage_East\" system-ip:1.1.1.3 user-name:\"mn2c\" user-id:2227",
	"HOST": "desktop-53",
	"FACILITY": "cron"
}

Using a python template Template

        mb["events"][0]['timestamp']=log_message['S_ISODATE'].decode("utf-8")

output

{
	"events": [
		{
			"attributes": {
				"!cisco.identifier": "Viptela",
				"!cisco.message_seperator": ":",
				"!cisco.mnemonic": "1400002",
				"!cisco.severity": "6",
				"!cisco.source": "sysmgrd",
				"!host": "desktop-83",
				"!sng.event.product": "viptela",
				"!sng.event.tags": [
					"wireformat:rfc",
					"wireformat:rfc3164",
					"source_identified",
					"msgtype:unstructured",
					"msg:unparsed"
				],
				"!sng.event.vendor": "cisco",
				"!syslog.facility": "daemon",
				"!syslog.host": "172.19.0.1",
				"!syslog.level": "err",
				"!syslog.pid": "919",
				"!syslog.program": "SYSMGR",
				"PID": "919",
				"PROGRAM": "SYSMGR",
				"message": "Notification: 3/17/2022 18:35:12 system-login-change severity-level:minor host-name:\"XYZ_vManage_East\" system-ip:1.1.1.3 user-name:\"mn2c\" user-id:2227"
			},
			"rawstring": "<27> Sep 17 16:43:15 SYSMGR[919]: %Viptela-desktop-83-sysmgrd-6-INFO-1400002: Notification: 3/17/2022 18:35:12 system-login-change severity-level:minor host-name:\"XYZ_vManage_East\" system-ip:1.1.1.3 user-name:\"mn2c\" user-id:2227",
			"timestamp": "2022-09-17T16:43:15+00:00"
		}
	],
	"tags": {
		"host": "desktop-83",
		"product": "viptela",
		"vendor": "cisco"
	}
}

[bazsi]

How S_ISODATE behaves in this regard depends on the frac-digits() setting in python the same way as everywhere else.

On Fri, Sep 16, 2022, 00:04 Ryan Faircloth @.***> wrote:

syslog-ng Version of syslog-ng

3.38.1 Platform

linux (docker) Steps to reproduce

using the following global

and having parsed a ts correct with msec the TS returned in the following python does not include ms

log_message['S_ISODATE'].decode("utf-8")

"timestamp": "2022-09-15T21:56:38+00:00",

— Reply to this email directly, view it on GitHub https://github.com/syslog-ng/syslog-ng/issues/4136, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAFOK5SVL62IKEPXK3B4EJDV6OMQNANCNFSM6AAAAAAQNZT4RU . You are receiving this because you are subscribed to this thread.Message ID: @.***>

[ryanfaircloth]

Yes that is what I expected I have

options {
        frac-digits(6);
        }

[ryanfaircloth]

@bazsi I updated the issue with output example using a JSON template and the same result using python

[bazsi]

I now identified this problem while fixing a related issue in #4142

The issue is briefly: right now, when a dynamic macro (e.g. the documentation calls these hard macros) is resolved through the LogMessage layer and not through a template, we use a distinct, global set of settings to store our formatting options, instead of the one associated with the configuration (e.g. the global config or the pipeline element that works with the LogMessage).

This means that options like frac-digits() or ts-format() are at their default values. which includes frac-digits(), more specifically:

/* timestamp format as specified by ts_format() / gint ts_format; / number of digits in the fraction of a second part, specified using frac_digits() */ gint frac_digits; gboolean use_fqdn;

/* timezone for LTZ_LOCAL/LTZ_SEND settings */ gchar *time_zone[LTZ_MAX];

I am not entirely sure how to resolve this properly. In such cases I could

1. sync the global config settings, which would probably resolve your specific issue, however this would mean that the inconsistent behaviour would remain: templates would use local settings while "raw" access through the LogMessage layer would not.

2. it'd be possible to expose the timestamps of the LogMessage as attributes, so that you'd get a proper DateTime instance when working with timestamps.

Or maybe the combination of both: at least use the global settings while exposing a different interface.

[ryanfaircloth]

combo of both would be good I was going to suggest a means of adding a special kv arg "timestamps" which is a dict with the three time stamps

[ryanfaircloth]

What if we had a "extended" python method that passed a object based on the format-json output from a template.