napalm-automation / napalm-logs

Cross-vendor normalisation for network syslog messages, following the OpenConfig and IETF YANG models
https://napalm-logs.readthedocs.io/en/latest/
Apache License 2.0
140 stars 43 forks source link

USER_EXIT_CONFIG_MODE regex filters not matching IOS #307

Open dpizzle opened 5 years ago

dpizzle commented 5 years ago

Hi,

The regex filters for USER_EXIT_CONFIG_MODE (%SYS-5-CONFIG_I) is matching against EOS messages, but not IOS. The Cisco switch is running 12.2(25)SEE4.

EOS example, which matches -

2019-09-05 10:25:14,455,456 [napalm_logs.listener.udp][DEBUG   ] [b'<165>Sep  5 11:25:14 arista_eos_1 ConfigAgent: %SYS-5-CONFIG_I: Configured from console by test_user on vty3 (1.1.1.1)\n'] Received ('2.2.2.2', 54159) from 1567679114.455575
2019-09-05 10:25:14,455,456 [napalm_logs.listener_proc][DEBUG   ] Received b'<165>Sep  5 11:25:14 arista_eos_1 ConfigAgent: %SYS-5-CONFIG_I: Configured from console by test_user on vty3 (1.1.1.1)\n' from 2.2.2.2. Queueing to the server.
2019-09-05 10:25:14,456,456 [napalm_logs.server][DEBUG   ] [2.2.2.2] Dequeued message from <165>Sep  5 11:25:14 arista_eos_1 ConfigAgent: %SYS-5-CONFIG_I: Configured from console by test_user on vty3 (1.1.1.1): 1567679114.4561913
2019-09-05 10:25:14,456,456 [napalm_logs.server][DEBUG   ] Matching under eos
2019-09-05 10:25:14,456,456 [napalm_logs.server][DEBUG   ] Matching using YAML-defined profiler:
2019-09-05 10:25:14,456,456 [napalm_logs.server][DEBUG   ] \<(\d+)\>(\w+ +\d+)\s+(\d\d:\d\d:\d\d)\s+([^ ]+)\s+(\w+)\:\s+\%([\w-]+)(.*)
2019-09-05 10:25:14,456,457 [napalm_logs.server][DEBUG   ] Adding eos to list of matched OS

IOS example, which does not match -

2019-09-05 10:24:13,240,240 [napalm_logs.listener.udp][DEBUG   ] [b'<157>Sep  5 10:24:12 cisco_ios_1 : %SYS-5-CONFIG_I: Configured from console by test_user on vty1 (1.1.1.1)\n'] Received ('2.2.2.2', 54159) from 1567679053.2401464
2019-09-05 10:24:13,240,240 [napalm_logs.listener_proc][DEBUG   ] Received b'<157>Sep  5 10:24:12 cisco_ios_1 : %SYS-5-CONFIG_I: Configured from console by test_user on vty1 (1.1.1.1)\n' from 2.2.2.2. Queueing to the server.
2019-09-05 10:24:13,240,241 [napalm_logs.server][DEBUG   ] [2.2.2.2] Dequeued message from <157>Sep  5 10:24:12 cisco_ios_1 : %SYS-5-CONFIG_I: Configured from console by test_user on vty1 (1.1.1.1): 1567679053.2407663
2019-09-05 10:24:13,241,241 [napalm_logs.server][DEBUG   ] Matching under ios
2019-09-05 10:24:13,241,241 [napalm_logs.server][DEBUG   ] Matching using YAML-defined profiler:
2019-09-05 10:24:13,241,241 [napalm_logs.server][DEBUG   ] \<(\d+)\>(\d+)\:\s+([^ ]+)\:\s+\*?(\w+\s+\d+)\s+(\d\d:\d\d:\d\d)\.(\d\d\d)\s?(\w+)?\:\s+\%([\w-]+)\:\s+Process\s+(\d+)\,\s+(.*)
2019-09-05 10:24:13,241,241 [napalm_logs.server][DEBUG   ] Match not found
2019-09-05 10:24:13,241,242 [napalm_logs.server][DEBUG   ] Matching using YAML-defined profiler:
2019-09-05 10:24:13,241,242 [napalm_logs.server][DEBUG   ] \<(\d+)\>(\d+)\:\s+([^ ]+)\:\s+\*?(\w+\s+\d+)\s+(\d\d:\d\d:\d\d)\.(\d+)\s?(\w+)?\:\s+\%([\w-]+)\:\s+(.*)
2019-09-05 10:24:13,241,242 [napalm_logs.server][DEBUG   ] Match not found
2019-09-05 10:24:13,241,242 [napalm_logs.server][DEBUG   ] No match found for ios
dpizzle commented 5 years ago

This regex pattern would match with 6 groups. Not sure where to add this pattern.

\<(\d+)\>(\w+ +\d+)\s+(\d\d:\d\d:\d\d)\s+([^ ]+)\s+\:\s+\%([\w-]+)(.*)
Group 1. | 1-4    | 157
Group 2. | 5-11   | Sep  5
Group 3. | 12-20  | 10:24:12
Group 4. | 21-47  | cisco_ios_1
Group 5. | 51-65  | SYS-5-CONFIG_I
Group 6. | 65-129 | : Configured from console by test_user on vty1 (1.1.1.1)\n
mirceaulinic commented 5 years ago

Hi @dpizzle - thanks for reporting this. You might need to add another header to https://github.com/napalm-automation/napalm-logs/blob/develop/napalm_logs/config/ios/init.yml.

Looking at that file, it seems that the IOS messages currently matched would need to start with a message ID (e.g., 521: router1: *Nov 14 08:30:56.699: %LINK-5-CHANGED: Interface GigabitEthernet2, changed state to administratively down). It seems like in your case you don't have this, but the format looks a little bit rearranged: Sep 5 10:24:12 cisco_ios_1 : %SYS-5-CONFIG_I which is {date} {time} {host} : %{tag}.

We have some documentation for this at http://napalm-logs.com/en/latest/developers/device_profiles.html#yaml-profiles, let me know if you have any questions.

dpizzle commented 4 years ago

Hi @mirceaulinic, maybe a slight shift in issue, but is there a way to distinguish between Cisco and Arista syslog messages for %SYS-5-CONFIG_I?

These both match the regex, so are reported as EOS each time -

<189>Oct  4 11:29:58 cisco_1 BST: %SYS-5-CONFIG_I: Configured from console by testuser on vty5 (1.1.1.1)\n
<165>Oct  4 11:35:45 arista_1 ConfigAgent: %SYS-5-CONFIG_I: Configured from console by testuser on vty3 (1.1.1.1)\n
\<(\d+)\>(\w+ +\d+)\s+(\d\d:\d\d:\d\d)\s+([^ ]+)\s+(\w+)\:\s+\%([\w-]+)(.*)
mirceaulinic commented 4 years ago

Ewww are they really the exact same? :nauseated_face: The tag (in this case SYS-5-CONFIG_I) is what we usually match on, e.g., https://github.com/napalm-automation/napalm-logs/blob/develop/napalm_logs/config/eos/USER_EXITED_CONFIG_MODE.yml#L4).

I don't have a Cisco IOS to check, but looking at the expected format we currently have, it'd suggest that the usual messages from IOS usually have column after the hostname, and also include a message ID, which I don't see in your example above. See here an example: https://github.com/napalm-automation/napalm-logs/blob/develop/napalm_logs/config/ios/init.yml#L2

Do you have both Arista and Cisco IOS in your environment? If the examples you shared above are accurate, at this point, can't really think of a good work around... Perhaps start two instances of napalm-logs, one with:

device_blacklist:
  - ios

and a second one (dedicated for IOS specifically) with:

device_whitelist:
  - ios

See http://napalm-logs.com/en/latest/options/index.html#device-whitelist for more details.