Ëpisode Name: Ëpisode 32 - Investigating Syslogs: Tips and Tricks
Contributors: Magnus Mortensen, Jay Johnston, David White Jr.
Posting Date: March 28, 2013
Description: The panel discusses best practices for configuring devices to generate syslogs, and how the TAC investigates syslogs provided by customers. Tips and tricks for parsing through large syslog files, as well as techniques and tools for finding useful information are discussed.
Listen Now (MP3 15.9 MB; 22:01 mins)
Subscribe to the Podcast in iTunes by clicking the image below:
About the Cisco TAC Security Podcast
The Cisco TAC Security Podcast Series is created by Cisco TAC engineers. Each show provides an in-depth technical discussion of Cisco product security features, with emphasis on troubleshooting.
Complete show listing and show information
Show Notes
Investigating a lot of logs can be daunting
For example, if someone provides you with 2 GB of syslogs, how do you parse through them to find the important information? If the text files are prepended with junk text from the a syslog server, how do you remove it? How do you sort your syslog entries?
The test syslog file used in the examples below can be found here:
https://www.dropbox.com/s/xhot7jblq43esoq/syslogs-TACSecurityPodcast.zip
This document focused on the use of command-line tools to get the job done.
Investigate the most severe syslogs generated by the ASA
Often we'll start investigating syslogs by looking at the most severe messages, and working our way down the severity list. For this we can easily use grep:
[10:48:10] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-1-" ASAlogs-TACSecurityPodcast.txt
[10:50:35] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-2-" ASAlogs-TACSecurityPodcast.txt
<162>Mar 28 2013 08:41:59: %ASA-2-106001: Inbound TCP connection denied from 173.36.62.103/80 to 10.10.103.38/64027 flags FIN ACK on interface outside
<162>Mar 28 2013 08:53:30: %ASA-2-106001: Inbound TCP connection denied from 72.163.43.97/80 to 10.10.103.38/64242 flags ACK on interface outside
<162>Mar 28 2013 08:53:38: %ASA-2-106001: Inbound TCP connection denied from 72.163.43.97/80 to 10.10.103.38/64243 flags ACK on interface outside
<162>Mar 28 2013 08:53:40: %ASA-2-106001: Inbound TCP connection denied from 72.163.43.97/80 to 10.10.103.38/64244 flags ACK on interface outside
<162>Mar 28 2013 08:53:41: %ASA-2-106001: Inbound TCP connection denied from 72.163.43.97/80 to 10.10.103.38/64245 flags ACK on interface outside
[10:50:39] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-3-" ASAlogs-TACSecurityPodcast.txt
<163>Mar 28 2013 08:26:23: %ASA-3-710003: TCP access denied by ACL from 10.150.53.63/51676 to outside:192.168.124.149/80
<163>Mar 28 2013 08:26:24: %ASA-3-710003: TCP access denied by ACL from 10.150.53.63/51676 to outside:192.168.124.149/80
<163>Mar 28 2013 08:26:25: %ASA-3-710003: TCP access denied by ACL from 10.150.53.63/51676 to outside:192.168.124.149/80
<163>Mar 28 2013 08:26:26: %ASA-3-710003: TCP access denied by ACL from 10.150.53.63/51676 to outside:192.168.124.149/80
<163>Mar 28 2013 08:26:27: %ASA-3-710003: TCP access denied by ACL from 10.150.53.63/51676 to outside:192.168.124.149/80
Browse through the syslogs by weeding out the logs you don't care about
By hiding the syslogs you don't care to see you are left with the messages that are most pertinent. Using 'grep -v' you can exclude log lines that match the text you provide:
[10:55:33] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6" ASAlogs-TACSecurityPodcast.txt | head -n 3
<166>Mar 28 2013 08:22:48: %ASA-6-305011: Built dynamic UDP translation from inside:10.10.103.38/61128 to outside:192.168.124.149/61128
<166>Mar 28 2013 08:22:48: %ASA-6-302015: Built outbound UDP connection 57958 for outside:192.168.108.43/53 (172.18.108.43/53) to inside:10.10.103.38/61128 (172.18.124.149/61128)
<166>Mar 28 2013 08:22:48: %ASA-6-302016: Teardown UDP connection 57958 for outside:192.168.108.43/53 to inside:10.10.103.38/61128 duration 0:00:00 bytes 563
[10:55:37] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6" ASAlogs-TACSecurityPodcast.txt | grep -v "ASA-6-305011" | head -n 3
<166>Mar 28 2013 08:22:48: %ASA-6-302015: Built outbound UDP connection 57958 for outside:192.168.108.43/53 (172.18.108.43/53) to inside:10.10.103.38/61128 (172.18.124.149/61128)
<166>Mar 28 2013 08:22:48: %ASA-6-302016: Teardown UDP connection 57958 for outside:192.168.108.43/53 to inside:10.10.103.38/61128 duration 0:00:00 bytes 563
<166>Mar 28 2013 08:22:49: %ASA-6-302015: Built outbound UDP connection 57959 for outside:192.168.108.43/53 (172.18.108.43/53) to inside:10.10.103.38/55143 (172.18.124.149/55143)
[10:55:41] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6" ASAlogs-TACSecurityPodcast.txt | grep -v "ASA-6-302011" | grep -v "ASA-6-302015" | head -n 3
<166>Mar 28 2013 08:22:48: %ASA-6-305011: Built dynamic UDP translation from inside:10.10.103.38/61128 to outside:192.168.124.149/61128
<166>Mar 28 2013 08:22:48: %ASA-6-302016: Teardown UDP connection 57958 for outside:192.168.108.43/53 to inside:10.10.103.38/61128 duration 0:00:00 bytes 563
<166>Mar 28 2013 08:22:49: %ASA-6-305011: Built dynamic UDP translation from inside:10.10.103.38/55143 to outside:192.168.124.149/55143
[10:56:04] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6" ASAlogs-TACSecurityPodcast.txt | grep -v "ASA-6-302011" | grep -v "ASA-6-302015" | grep -v "ASA-6-305011" | head -n 3
<166>Mar 28 2013 08:22:48: %ASA-6-302016: Teardown UDP connection 57958 for outside:192.168.108.43/53 to inside:10.10.103.38/61128 duration 0:00:00 bytes 563
<166>Mar 28 2013 08:22:49: %ASA-6-302016: Teardown UDP connection 57959 for outside:192.168.108.43/53 to inside:10.10.103.38/55143 duration 0:00:00 bytes 264
<166>Mar 28 2013 08:22:49: %ASA-6-302016: Teardown UDP connection 57960 for outside:192.168.108.43/53 to inside:10.10.103.38/62819 duration 0:00:00 bytes 188
[10:56:19] [jay@jajohnst-pc /mnt/storage/logs]$
Remove junk text at the start of each syslog line
You'll notice that each log line has some junk at the front that should be removed:
[10:43:27] [jay@jajohnst-pc /mnt/storage/logs]$ head -n 4 ASAlogs-TACSecurityPodcast.txt
<167>Mar 28 2013 08:22:48: %ASA-7-710005: UDP request discarded from 10.10.126.99/52470 to inside:255.255.255.255/69
<166>Mar 28 2013 08:22:48: %ASA-6-305011: Built dynamic UDP translation from inside:10.10.103.38/61128 to outside:192.168.124.149/61128
<167>Mar 28 2013 08:22:48: %ASA-7-609001: Built local-host outside:192.168.108.43
<166>Mar 28 2013 08:22:48: %ASA-6-302015: Built outbound UDP connection 57958 for outside:192.168.108.43/53 (172.18.108.43/53) to inside:10.10.103.38/61128 (172.18.124.149/61128)
[10:46:15] [jay@jajohnst-pc /mnt/storage/logs]$
To remove all the charactors on the line leading up to "Mar 28", use the sed program to find and replace that text with "nothing":
[10:48:03] [jay@jajohnst-pc /mnt/storage/logs]$ cat ASAlogs-TACSecurityPodcast.txt | sed 's/^.*Mar 28/Mar 28/g' | head -n 4
Mar 28 2013 08:22:48: %ASA-7-710005: UDP request discarded from 10.10.126.99/52470 to inside:255.255.255.255/69
Mar 28 2013 08:22:48: %ASA-6-305011: Built dynamic UDP translation from inside:10.10.103.38/61128 to outside:192.168.124.149/61128
Mar 28 2013 08:22:48: %ASA-7-609001: Built local-host outside:192.168.108.43
Mar 28 2013 08:22:48: %ASA-6-302015: Built outbound UDP connection 57958 for outside:192.168.108.43/53 (172.18.108.43/53) to inside:10.10.103.38/61128 (172.18.124.149/61128)
[10:48:10] [jay@jajohnst-pc /mnt/storage/logs]$
Just display a particular portion of each line in the syslog file
Lets say you want to just display something particular from each line, say, the global IP and port in the message like this:
<166>Mar 28 2013 08:22:50: %ASA-6-305011: Built dynamic TCP translation from inside:10.10.103.38/63894 to outside:192.168.124.149/63894
First, you would grep the file to just output the lines that contained that text, and next you could use the cut command to break the line into tokens, and just display a particular token. In this example, the global interface, ip and port are token number 13, as delimited by the space character:
[11:00:49] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6-305011" ASAlogs-TACSecurityPodcast.txt | cut -f 13 -d ' '
outside:192.168.124.149/61128
outside:192.168.124.149/55143
outside:192.168.124.149/62819
outside:192.168.124.149/60989
outside:192.168.124.149/50843
outside:192.168.124.149/63916
outside:192.168.124.149/58818
...
Now lets say you wanted to get rid of the 'outside' text at the start of each line. Use sed to replace that text with nothing:
[11:03:30] [jay@jajohnst-pc /mnt/storage/logs]$ grep "ASA-6-305011" ASAlogs-TACSecurityPodcast.txt | cut -f 13 -d ' ' | sed 's/outside://g'
192.168.124.149/61128
192.168.124.149/55143
192.168.124.149/62819
192.168.124.149/60989
192.168.124.149/50843
Challenge!
Around 8:32 on March 28th 2013, the CPU usage on this ASA increased. Determine why
Use the less command to "jump ahead" to the time in question to see if anything stands out as suspicious
