Splunk – Cisco Change Tracking

One of the main challenges lots of companies have is Change Control and Change Tracking. This is especially true in a large Cisco deployment as you’ll most likely have more than one network admin capable of making changes.

I was looking at this on behalf of a client. They have a small permanent team, but also have to allow limited configuration access from 3rd parties during busy periods in the year.

Now, Cisco provides a very useful log message for whenever any configuration command is entered. This is:

%PARSER-5-CFGLOG_LOGGEDCMD

To enable these, you’ll need to enter the following into your device configuration (this is based on IOS 12 on a Catalyst 3750):

archive
 log config
  logging enable
  logging size 200
  notify syslog contenttype plaintext
  hidekeys

Checkout the full Cisco article on ‘Configuration Change Notification and Logging‘ for more detail.

Another command that you’ll need to add is this:

service sequence-numbers

This has the effect of adding a sequence number at the start of every log entry. (We’ll touch on why this is important later on.)

Now, to test that this is all working, enter configuration mode on your cisco device and try a few commands. Exit out of this mode and do a ‘show log’. You should get entries like this:

000001: Nov 01 13:34:18.035 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:interface FastEthernet1/0/18
000002: Nov 01 13:34:28.218 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:description [WebCam]
000003: Nov 01 13:34:37.983 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:switchport access vlan 104
000004: Nov 01 13:35:01.933 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:no shutdown
000005: Nov 01 13:35:05.534 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:exit

You can also use this command to see the archive log: show archive log config all

idx sess user@line Logged command
283 21 gmor@vty0 |interface FastEthernet1/0/18
284 21 gmor@vty0 | description [WebCam]
285 21 gmor@vty0 | switchport access vlan 104
286 21 gmor@vty0 | no shutdown
287 21 gmor@vty0 | exit

So, if that’s working, then that’s half the battle won. This is great for single devices, but for a large estate, we need to be able to analyse results from multiple devices. This sounds like an excellent use for Splunk.

I’m going to make the assumption that you’ve got your Splunk instance up and running, with your Cisco devices logging to it. If not, have a quick read of this article first: Splunk – Cisco Logging Nirvana.

With all of my log messages going to Splunk, I can now do a quick search for all of my configuration syslog entries. Something like this should do the job and be specific enough:

%PARSER

(Remember in Splunk to always try to constrain you time range. There’s no point making Splunk search across ‘All time’ when you know you’re only looking for information that happened in the last 24 hours)

This should give me:

Aug 25 13:35:06 switchname.null.com 508: 000005: Aug 25 13:35:05.534 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:exit
Aug 25 13:35:02 switchname.null.com 507: 000004: Aug 25 13:35:01.933 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:no shutdown
Aug 25 13:34:38 switchname.null.com 506: 000003: Aug 25 13:34:37.983 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:switchport access vlan 104
Aug 25 13:34:28 switchname.null.com 505: 000002: Aug 25 13:34:28.218 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:description [WebCam]
Aug 25 13:34:18 switchname.null.com 504: 000001: Aug 25 13:34:18.035 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:interface FastEthernet1/0/18

The first thing which should be obvious it that the sequence is reversed. I.e. I tend to read from top to bottom, so it’s confusing to see that the first command I entered was ‘exit’ followed by ‘no shutdown’. No problem, this is an easy fix using the Splunk search language:

%PARSER | reverse

Now we should get this:

Aug 25 13:34:18 switchname.null.com 504: 000001: Aug 25 13:34:18.035 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:interface FastEthernet1/0/18
Aug 25 13:34:28 switchname.null.com 505: 000002: Aug 25 13:34:28.218 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:description [WebCam]
Aug 25 13:34:38 switchname.null.com 506: 000003: Aug 25 13:34:37.983 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:switchport access vlan 104
Aug 25 13:35:02 switchname.null.com 507: 000004: Aug 25 13:35:01.933 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:no shutdown
Aug 25 13:35:06 switchname.null.com 508: 000005: Aug 25 13:35:05.534 BST: %PARSER-5-CFGLOG_LOGGEDCMD: User:gmor logged command:exit

This is better, but it’s still difficult to read exactly what’s been entered and by whom. So the next step is to extract some of the key information into fields. For this, we’ll use the Splunk ‘rex’ command. This is the Regular Expression extractor. The key information that I want from each message is:

User
Command
Sequence #

To get each of these fields, I’ll use the following ‘rex’ extractions:

User = rex “User:(?<user>[\S]*)”
Command = rex “command:(?<command>[^\$]*)”
Sequence # = rex “\s[\d]*:\s(?<sequence>[\d]*)”

Combining this into a search string, I would now use:

%PARSER | rex “User:(?<user>[\S]*)” | rex “command:(?<command>[^\$]*)” | rex “\s[\d]*:\s(?<sequence>[\d]*)” | reverse

Now on the left-side of your results, you should see some new fields:

Whilst this search looks complicated, now that we know the field extractions work, we can actually move these expressions into Splunk’s ‘props.conf’ file.

If you’re categorising your Cisco syslog messages into sourcetypes (as described here), then you could created the following in your /splunk/etc/system/local/props.conf file:

[syslog-cisco-PARSER]
EXTRACT-user = User:(?<user>[\S]*)
EXTRACT-command = command:(?<command>[^\$]*)
EXTRACT-sequence = \s[\d]*:\s(?<sequence>[\d]*)

After doing this, restart Splunk to ensure that the new configuration is re-read.

Now we can go back to using our simple search expression:

%PARSER | reverse

And we should still be getting the ‘user, command and sequence’ fields on the left-hand side of the results.

So what now? Well, it’s entirely up to you. There are a number of reports that I think are very useful.
 

1. Table of Configuration Commands by Host

%PARSER | sort -host, +sequence | table _time host user sequence command

Here we’re sorting first by the ‘host’ field, then by ‘sequence’. The reason for using sequence numbers is that commands can get jumbled if you just rely on the ‘_time’ field. We found that when Administrators were pasting configs into devices, the 1 second time stamping resolution in Splunk wasn’t enough.

This search should generate a table similar to this:

 

2. Timechart of Configuration Commands by Host

%PARSER | timechart span=1h limit=20 count by host

This is a great visual cue to put onto a dashboard, to see which devices are being changed the most:

(If the host names look slightly strange, it’s because they’ve been ‘scrubbed‘ to protect the innocent…)
 

3. Timechart of Configuration Commands by User

%PARSER | timechart span=1h limit=20 count by user

Again, another very simple way of seeing who is making changes. This one’s great for spotting people who shouldn’t be making changes as their names clearly stand out:

 

For the client in question, this approach gave them a whole new level of visibility into the who, what and when associated with running the network.
 

PS

For the adventurous amongst you, if you’re running ASA Firewalls, you could do a similar things here too. The messages that you’re looking for is:

%ASA-5-111008

So a search similar to this should give you what you need:

%ASA-5-111008 | rex “User\s’(?<user>[^']+)” | rex “executed\sthe\s’(?<command>[^']+)” | sort +_time | table _time host user command

(You’ll also notice that there’s no sequence number that you can use to order the results, so you may get a couple of commands out of sequence if they have the same timestamp)

Enjoy!

Advertisement