Cisco Expressway - Timestamp not extracted correctly

[Stjubit]

Was the issue replicated by support?

No.

What is the sc4s version ?

3.22.1

Is there a pcap available?

Yes. On-demand if needed.

Is the issue related to the environment of the customer or Software related issue?

The source is weird (looking at you Cisco), but it's an issue in the sc4s parser.

Is it related to Data loss, please explain ?

Not related to data loss.

Last chance index/Fallback index?

No.

Is the issue related to local customization?

No.

Do we have all the default indexes created?

Yes.

Describe the bug

Cisco Expressway is sending syslog messages with extra headers. Example:

<host_removed>.31727 > 10.111.223.206.syslog: [udp sum ok] SYSLOG, length: 549
    Facility local6 (22), Severity info (6)
    Msg: 1 2024-03-18T16:54:33.000+01:00 <host_removed> tvcs - - [meta sequenceId="1447"] 2024-03-18T16:54:33.209+01:00 <host_removed> tvcs: UTCTime="2024-03-18 15:54:33,209" Module="network.sip" Level="INFO":  Action="Sent" Local-ip="<local_ip_removed>" Local-port="7001" Dst-ip="<dst_ip_removed>" Dst-port="25002" Detail="Sending Response Code=401, Method=OPTIONS, CSeq=17996, To=sip:<removed>:7001, Call-ID=<removed>, From-Tag=<removed>, To-Tag=<removed>, Msg-Hash=<removed>, Local-SessionID=, Remote-SessionID="\0x0a\0x0a

So the first timestamp in the Syslog message always has .000 set as milliseconds and sc4s uses it for timestamp extraction.

However, there is a field UTCTime that should be used for timestamp extraction.

More infos can be found in the Slack user group discussions: https://splunk-usergroups.slack.com/archives/CNV918JCQ/p1710779436509039.

To Reproduce

Ingest Cisco Expressway logs and check _time.

[mstopa-splunk]

Hi @Stjubit right, interesting issue :) Please send the pcap to mstopa@splunk.com or through Splunk support

[Stjubit]

Hi @mstopa-splunk,

thx for the quick reply!

I'm not sure what's the best way to anonymize a packet capture, so I hope example Syslogs are also fine for you:

1) tvcs Syslog:

echo '1 2024-03-19T13:43:27.000+01:00 expresswayhost tvcs - - [meta sequenceId="7675"] 2024-03-19T13:43:27.621+01:00 expresswayhost tvcs: UTCTime="2024-03-19 12:43:27,620" Module="network.sip" Level="INFO":  Action="Sent" Local-ip="1.2.3.4" Local-port="1234" Dst-ip="5.6.7.8" Dst-port="5678" Detail="Sending Response Code=200, Method=REGISTER, CSeq=307, To=sip:+43123456789012@expresswayhost.test.com, Call-ID=1c5c6e77-b6e2-480a-8735-3cce697f1127@1.2.3.4, From-Tag=001234567890abcdef-00001234, To-Tag=123456789, Msg-Hash=123456789123456, Local-SessionID=001234567890abcdef001234567890abcdef, Remote-SessionID=001234567890abcdef"' | nc -v -u -w 0 <sc4s_ip> <sc4s_port>

2) licensemanager Syslog:

echo '1 2024-03-19T10:19:23.348+01:00 expresswayhost licensemanager - - [meta sequenceId="8034"] 2024-03-19T10:19:23.348+01:00 expresswayhost licensemanager: Level="INFO" Detail="License granted" call_id="1c5c6e77-b6e2-480a-8735-3cce697f1127" lic_type="collabedge tokens=1" UTCTime="2024-03-19 09:19:23,347"' | nc -v -u -w 0 <sc4s_ip> <sc4s_port>

Both logs are sent by Cisco expressway, but the current app parser only matches for Syslog app tvcs. It might be a good idea to rework the filter for this source, too.

The slack discussion in the user group gives more insights into this issue: https://splunk-usergroups.slack.com/archives/CNV918JCQ/p1710779436509039.

[mstopa-splunk]

sure, those work fine too. Ok let me take a look, this may take some time because it's not an easy case