parse pix/asa logs

December 16, 2010 5:05 AM

Trying to create a Perl or shell script to parse/convert Cisco PIX/ASA logs into a CSV format. Has anyone had any success with this? Since all messages aren't standard, I'm trying to think of the best way to approach this issue. Has anyone had any success, or have a good AWK, Grep, SED, or perl script that can get this done?
posted by fozzie33 to Computers & Internet (17 answers total)

Have you tried fwlog and text::CSV ?
posted by I_pity_the_fool at 5:30 AM on December 16, 2010

This is kind of a round about way to do this, but have you considered Splunk? It can do that, and also just generally makes it easy to search and browse any kind of logs.
posted by empath at 5:35 AM on December 16, 2010

Response by poster: have considered splunk, but not practical with the amount of data... we want to automate this because we are getting 1-3 gigs of logs a day, (syslog server from large enterprise)
posted by fozzie33 at 5:49 AM on December 16, 2010

You can schedule Splunk to automatically run reports and searches. And it definitely handles gigs of traffic. I put our DHCP logs on it (I work at an isp) which was gigs and gigs of traffic, and it handled it fine.
posted by empath at 6:02 AM on December 16, 2010

What do you mean by "messages aren't standard"? I don't think I've seen a log message from a device that wasn't standard/consistent in some manner. I've done some processing of various Cisco router/vpn and switches from other vendors logs for ACL rule hits and haven't run into anything that was terribly hard to grok into various fields depending on message type. What is it about a PIX log that is so hard to parse?
posted by zengargoyle at 6:04 AM on December 16, 2010

Not familiar with the format. Is it line by line? Any identifiers to distinguish one kind of entry from another?

The general form I use for stuff like this is:

Some kind of function to figure out what kind of entry it is. I generally use a dispatch table to call the relevant function that deals with that kind of entry.

Some kind of funtion (one for each kind of entry) to mung that into a generic hash.

Some kind of funtion to turn that hash into CSV.
posted by vbfg at 6:10 AM on December 16, 2010

Response by poster: first five fields are standard, then they get crazy
sample:
Full PIX log sample 1

Sep 7 06:25:17 PIXName %PIX-7-710005: UDP request discarded from 0.0.0.0/68 to outside:255.255.255.255/67
Sep 7 06:25:23 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:23 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:23 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:24 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:24 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:24 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:25 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:25 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:25 PIXName %PIX-7-710005: UDP request discarded from 1.1.1.1/137 to outside:1.1.1.255/137
Sep 7 06:25:28 PIXName %PIX-7-609001: Built local-host db:10.0.0.1
Sep 7 06:25:28 PIXName %PIX-6-302013: Built inbound TCP connection 141968 for db:10.0.0.1/60749 (10.0.0.1/60749) to NP Identity Ifc:
10.0.0.2/22 (10.0.0.2/22)
Sep 7 06:25:28 PIXName %PIX-7-710002: TCP access permitted from 10.0.0.1/60749 to db:10.0.0.2/ssh
Sep 7 06:26:20 PIXName %PIX-5-304001: 203.87.123.139 Accessed URL 10.0.0.10:/Home/index.cfm
Sep 7 06:26:20 PIXName %PIX-5-304001: 203.87.123.139 Accessed URL 10.0.0.10:/aboutus/volunteers.cfm
Sep 7 06:26:49 PIXName %PIX-4-106023: Deny udp src outside:204.16.208.49/58939 dst dmz:10.0.0.158/1026 by access-group
"acl_outside" [0x0, 0x0]
Sep 7 06:26:49 PIXName %PIX-4-106023: Deny udp src outside: 204.16.208.49/58940 dst dmz:10.0.0.158/1027 by access-group
"acl_outside" [0x0, 0x0]
Sep 7 06:31:26 PIXName %PIX-7-711002: Task ran for 330 msec, Process= ssh_init, PC = fddd93, Traceback = 0x00FF1E6B 0x00FE1890
0x00FE0D3C 0x00FD326A 0x00FC0BFC 0x00FDBB8E 0x00FDBA4D 0x00FCD846 0x00FBF09C 0x001C76AE
0x00A01512 0x009CF6B5 0x00BDB9CE 0x00BDA502
posted by fozzie33 at 6:11 AM on December 16, 2010

Response by poster: or:
%PIX-7-710005: UDP request discarded from 192.168.2.190/137 to outside:192.168.2.255/netbios-ns
%PIX-6-315011: SSH session from 192.168.2.10 on interface outside for user "roo
" disconnected by SSH server, reason: "TCP connection closed" (0x03)
%PIX-6-604101: DHCP client interface outside: Allocated ip = 192.168.2.11, mask = 255.255.255.0, gw = 192.168.2.1
%PIX-6-604101: DHCP client interface outside: Allocated ip = 192.168.2.14, mask = 255.255.255.0, gw = 192.168.2.1
%PIX-6-604103: DHCP daemon interface inside: address granted 000c.29e4.ebc3 (12.168.1.3)
%PIX-6-604103: DHCP daemon interface inside: address granted 000c.29e4.ebc3 (12.168.1.4)
%PIX-6-604103: DHCP daemon interface inside: address granted 0100.0d9d.8283.ec(192.168.1.2)
%PIX-6-605004: Login denied from 192.168.2.10/13269 to outside:192.168.2.14/ssh for user "root"
%PIX-6-605004: Login denied from 192.168.2.10/13528 to outside:192.168.2.14/ssh for user "dcid"
%PIX-6-605004: Login denied from 192.168.2.10/14154 to outside:192.168.2.14/ssh for user "root"
%PIX-3-305006: portmap translation creation failed for tcp src inside:192.168.1.2/2893 dst outside:192.168.2.99/3128
%PIX-3-305006: portmap translation creation failed for tcp src inside:192.168.1.2/2892 dst outside:192.168.2.99/3128
%PIX-3-201008: The PIX is disallowing new connections.
%PIX-3-106011: Deny inbound (No xlate) udp src outside:192.168.2.1/137 dst outside:192.168.2.14/137
%PIX-3-106011: Deny inbound (No xlate) tcp src outside:63.245.209.21/80 dst outside:192.168.2.14/1823
%PIX-3-106011: Deny inbound (No xlate) tcp src outside:195.27.11.150/80 dst outside:192.168.2.14/1717
%PIX-3-106011: Deny inbound (No xlate) tcp src outside:195.27.11.150/80 dst outside:192.168.2.14/1716
%PIX-3-106011: Deny inbound (No xlate) tcp src outside:195.27.11.143/80 dst outside:192.168.2.14/1721
%PIX-3-106011: Deny inbound (No xlate) tcp src outside:195.27.11.142/80 dst outside:192.168.2.14/1720
posted by fozzie33 at 6:12 AM on December 16, 2010

Do you want essentially a file of the 5 standard fields + everything else or are you attempting to make sense of the everything else and break that down as well into its component parts?
posted by mmascolino at 6:24 AM on December 16, 2010

Response by poster: need everything parsed, so first five fields, then series of fields to do the rest, so source ip, src pt, dest ip, dest prt, etc.... some will be blank depending on type of log, but need all data parsed...
posted by fozzie33 at 6:30 AM on December 16, 2010

seems fairly straight forward to parse this log file. Perl would be something like:

while(<>) {

if (/(.*): Deny inbound.* (\d+\.\d+\.\d+\.\d+\/\d+).*(\d+\.\d+\.\d+\.\d+\/\d+)/) {
print OUTFILE "$1,DENY_INBOUND,$2,$3\n"; }

if (/(.*): SSH session.* (\d+\.\d+\.\d+\.\d+\/\d+).*user \"(.*)\".*reason: \"(.*)\" \(0x(\d+)\)/) {
print OUTFILE "$1,SSH_DISCONNECT,\"$2\",\"$3\",$4\n"; }

.
.
.

}
posted by blueyellow at 6:33 AM on December 16, 2010

We solved this problem at a previous employer by conditional handling based on the event number field. Have your script pre-parse the logfile and ensure that you have a handler for each event number in the log. Add them as needed. Really, you're only going to see a small percent of the possible events over the course of a year.
posted by bfranklin at 7:13 AM on December 16, 2010

Yeah, this is a one message class - one parser type of thing, and I don't see the benefit of trying to stuff it all into the same CSV table, bad data normalization practice there but...

#!/usr/bin/perl
use strict;
use warnings;

my %dispatch = ( 'PIX-7-710005' => \&do_discarded, );

while (<>) {
if (/^(?:(.*?) )?%(PIX-\d-\d+): (.*)$/) {

# possibly extra fields default to ''
my %extra = ();
$extra{$_} = '' for qw/mm dd hms name/;

# handle $1 as date/hostname if available.
if ($1) {
@extra{qw/mm dd hms name/} = split /\s/, $1;
}

# try and find a parser for this type
my $handler = $dispatch{$2};
unless ($handler) {

#warn "No handler for message type $2\n";
next;
}

# call our handler
my $rec = $handler->($3);

# print our CSV line
print join( ",",
@extra{qw/mm dd hms name/},
@$rec{qw/action proto srcip srcport dstip dstport dstif/} ),
"\n";
}
else {

# not a PIX message
}
}

sub do_discarded {
my $line = shift;
my %f = ();

# rip out fields for 7-710005 message
@f{qw/proto request action from src to dst/} = split /\s/, $line;

# extract ip/port from src
@f{qw/srcip srcport/} = split /\//, delete $f{src};

# extract if:ip/port from dst
@f{qw/dstif dstip dstport/} = split /[\/:]/, delete $f{dst};

# delete static fields
delete @f{qw/from to request/};
return \%f;
}
__END__


$ perl foo.pl < foo.pix
Sep,7,06:25:17,PIXName,discarded,UDP,0.0.0.0,68,255.255.255.255,67,outside
Sep,7,06:25:23,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:23,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:23,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:24,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:24,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:24,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:25,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:25,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
Sep,7,06:25:25,PIXName,discarded,UDP,1.1.1.1,137,1.1.1.255,137,outside
,,,,discarded,UDP,192.168.2.190,137,192.168.2.255,netbios-ns,outside

Is the rough idea. each message class in itself is not hard to parse, machines output very regular information. If speed becomes an issue you can switch from regex matching to good old index and substr (find 'PIX', extract 12 characters, etc.). I've only had problems with speed with some gigantic look through past 30 days of logs quickly problems (2 /16s and a /20s worth).
posted by zengargoyle at 7:50 AM on December 16, 2010

Best answer: Ah, so the number in PIX-#-###### indicates the format of the rest of the line? I haven't benchmarked but my guess is that this would be a faster version of zengargoyle's code (and not hard to read):

while (<>) {
if (!/^(... \d+ [\d:]+) (\S+) %PIX-: /g) {
   Whoa, this doesn't look like a logfile line. 
   Deal with it however you want.
   next;
}

@csv = ( Parse $1 (the date) and $2 (PIXname) into @csv );

# One regexp for each line format
if (/\G5-304001: ([\d\.]+) Accessed URL (.*)$/c) {
   push(@csv, 'accessed', Parse $1 (the IP address) and $2 (the URL)  );
} elsif (/\G3-106011: Deny inbound \(No xlate\) (\S+) src (\S+):([\d\.]+)\/(\d+) dst (\S+):([\d\.]+)\/(\d+)$/c) {
   # e.g., $1 = 'udp', $2 = 'outside', $3 = '192.168.2.1', $4 = '137', ...
   push(@csv, stuff );
} else {
   Unrecognized record type. Do whatever you want
}

print OUTFILE join(',', ...some function on @csv if comma-quoting is needed ...)."\n";
}

Note the use of /g, /c, \G to avoid string copies, and capture patterns designed to avoid backtracking. I'm assuming that the number of distinct record types isn't huge, otherwise, go with the hash-of-subs approach.
posted by hattifattener at 11:14 AM on December 16, 2010 [1 favorite]

Hats off to hattifattener. Roughly 2.5x faster than hash and 2x faster once my version is changed to array from split (via Benchmark with some mucking to make them equivalent for testing). Though I do get "Use of /c modifier is meaningless without /g" warning... I'd have thought splitting on space would beat regex with character classes but I guess copying kills. Though not as fast as arrays, hashes are handy when you want to fiddle with the output, much easier to remember than column numbers. (and forgot my pre tag, code was pretty)
posted by zengargoyle at 1:04 PM on December 16, 2010

Response by poster: thanks, I think i am going to go down that route...
I'll do a
Gawk '{print $5}' logFileName | sort | uniq -c | sort -n
to find the most common ASA/PIX messages and focus my coding on those, then have a catch all to capture anything not captured and print to an error/continuing file....
posted by fozzie33 at 4:03 AM on December 17, 2010

Response by poster: for those curious, her is the count from yesterday of types of ASA Logs and their formats (from Cisco doc)

Count Log Type LogFormat
18132395 %ASA-6-302015: Built {inbound|outbound} UDP connection number for interface_name:real_address/real_port (mapped_address/mapped_port) to interface_name:real_address/real_port (mapped_address/mapped_port) [(user)]
18123239 %ASA-6-302016: Teardown UDP connection number for interface:real-address/real-port to interface:real-address/real-port duration hh:mm:ss bytes bytes [(user)]
9098811 %ASA-6-302014: Teardown TCP connection id for interface:real-address/real-port to interface:real-address/real-port duration hh:mm:ss bytes bytes [reason] [(user)]
9097915 %ASA-6-302013: Built {inbound|outbound} TCP connection_id for interface:real-address/real-port (mapped-address/mapped-port) to interface:real-address/real-port (mapped-address/mapped-port) [(user)]
4017138 %ASA-4-106023: Deny protocol src [interface_name:source_address/source_port] dst interface_name:dest_address/dest_port [type {string}, code {code}] by access_group acl_ID
2646225 %ASA-6-305012: Teardown {dynamic|static} {TCP|UDP|ICMP} translation from interface_name [(acl-name)]:real_address/{real_port|real_ICMP_ID}to interface_name:mapped_address/{mapped_port|mapped_ICMP_ID} duration time
2645583 %ASA-6-305011: Built {dynamic|static} {TCP|UDP|ICMP} translation from interface_name:real_address/real_port to interface_name:mapped_address/mapped_port
768037 %ASA-6-302020: Built {in | out}bound ICMP connection for faddr {faddr | icmp_seq_num} gaddr {gaddr | cmp_type} laddr laddr
767977 %ASA-6-302021: Teardown ICMP connection for faddr {faddr | icmp_seq_num} gaddr {gaddr | cmp_type} laddr laddr
468749 %ASA-6-106015: Deny TCP (no connection) from IP_address/port to IP_address/port flags tcp_flags on interface interface_name.
141597 %ASA-3-305006: {outbound static|identity|portmap|regular) translation creation failed for protocol src interface_name:source_address/source_port dst interface_name:dest_address/dest_port
9917 %ASA-4-733100: Object drop rate rate_ID exceeded. Current burst rate is rate_val per second, max configured rate is rate_val; Current average rate is rate_val per second, max configured rate is rate_val; Cumulative total count is total_cnt
6095 %ASA-3-305005: No translation group found for protocol src interface_name: source_address/source_port dst interface_name: dest_address/dest_port
1267 %ASA-6-106100: access-list acl_ID {permitted | denied | est-allowed} protocol interface_name/source_address(source_port) - interface_name/dest_address(dest_port) hit-cnt number ({first hit | number-second interval}) hash codes
219 %ASA-6-314001: Pre-allocated RTSP UDP backconnection for src_intf:src_IP to dst_intf:dst_IP/dst_port.
164 %ASA-5-111008: User user executed the command string
143 %ASA-6-302010: connections in use, connections most used
138 %ASA-4-313005: No matching connection for ICMP error message: icmp_msg_info on interface_name interface. Original IP payload: embedded_frame_info icmp_msg_info = icmp src src_interface_name:src_address dst dest_interface_name:dest_address (type icmp_type, code icmp_code) embedded_frame_info = prot src source_address/source_port dst dest_address/dest_port
95 %ASA-6-110002: Failed to locate egress interface for protocol from src interface:src IP/src port to dest IP/dest port
90 %ASA-6-602303: IPSEC: An direction tunnel_type SA (SPI=spi) between local_IP and remote_IP (username) has been created.
90 %ASA-6-602304: IPSEC: An direction tunnel_type SA (SPI=spi) between local_IP and remote_IP (username) has been deleted.
88 %ASA-6-303002: FTP connection from src_ifc:src_ip/src_port to dst_ifc:dst_ip/dst_port, user username action file filename
59 %ASA-4-419002: Received duplicate TCP SYN from in_interface:src_address/src_port to out_interface:dest_address/dest_port with different initial sequence number.
48 %ASA-5-713041: IKE Initiator: new or rekey Phase 1 or 2, Intf interface_number, IKE Peer IP_address local Proxy Address IP_address, remote Proxy Address IP_address, Crypto map (crypto map tag)
45 %ASA-5-713049: Security negotiation complete for tunnel_type type (group_name) Initiator/Responder, Inbound SPI = SPI, Outbound SPI = SPI
45 %ASA-3-713020: No Group found by matching OU(s) from ID payload: OU_value
28 %ASA-3-313001: Denied ICMP type=number, code=code from IP_address on interface interface_name
27 %ASA-6-611101: User authentication succeeded: Uname: user
26 %ASA-1-709003: (Primary) Beginning configuration replication: Sending to mate.
18 %ASA-6-113004: AAA user aaa_type Successful: server = server_IP_address, User = user
18 %ASA-6-113008: AAA transaction status ACCEPT: user = user
11 %ASA-6-315011: SSH session from IP_address on interface interface_name for user user disconnected by SSH server, reason: reason
9 %ASA-5-502103: User priv level changed: Uname: user From: privilege_level To: privilege_level
9 %ASA-5-611103: User logged out: Uname: user
9 %ASA-6-605005: Login permitted from source-address/source-port to interface:destination/service for user “username”
6 %ASA-5-713050: Connection terminated for peer IP_address. Reason: termination reason Remote Proxy IP_address, Local Proxy IP_address
5 %ASA-4-313004:Denied ICMP type=icmp_type, from source_address on interface interface_name to dest_address:no matching session
5 %ASA-5-111007: Begin configuration: IP_address reading from device.
4 %ASA-5-111001: Begin configuration: IP_address writing to device
4 %ASA-5-111004: IP_address end configuration: {FAILED|OK}
4 %ASA-5-111005: IP_address end configuration: OK
4 %ASA-6-611102: User authentication failed: Uname: user
3 %ASA-4-713903:descriptive_event_string
3 %ASA-5-713119: PHASE 1 COMPLETED
3 %ASA-6-713172: Automatic NAT Detection Status: Remote end is|is not behind a NAT device This end is|is not behind a NAT device
2 %ASA-6-113005: AAA user authentication Rejected: reason = string: server = server_IP_address, User = user
1 %ASA-6-110003: Routing failed to locate next-hop for protocol from src interface:src IP/src port to dest interface:dest IP/dest port
posted by fozzie33 at 7:33 AM on December 17, 2010