HOME
SCRIPTS
PROJECTS
READING
CV
Log Templater (logtemplater) can be found on SourceForge.
What is tmpltr?
Templater is a small and fast log processor that provides simple artificial ignorance capabilities. You use the tool to process past log data and store templates that represent normal log line structures. You then run the tool against current or target logs and all normal patterns are automatically ignored. The parser is fast and capable of processing millions of lines per minute. Log Templater runs pretty fast. The following mentrics were generated in a Linux VM running on an i7 @ 3.2GHz.| Log size and type | Avg. Line Len | Avg. Arg Count | Args Stored | Avg. Lines per Min |
| 18M Line Cisco FW Log | 180 | 32 | 0 | 12,004,023/min |
| 18M Line Cisco FW Log (Clustered) | 180 | 32 | 24,009 | 4,093,802/Min |
| 11M Line Apache Access Log | 246 | 44 | 0 | 9,453,905/Min | 11M Line Apache Access Log (Clustered) | 246 | 44 | 21,666 | 5,563,009/Min | 17M Line UNIX Auth Log | 168 | 24 | 0 | 5,083,004/Min | 17M Line UNIX Auth Log (Clustered) | 168 | 24 | 52,318 | 5,121,656/Min | 4M Line Windows Event Log | 793 | 90 | 0 | 2,854,123/Min | 4M Line Windows Event Log (Clustered) | 881 | 129 | 70,361 | 1,183,226/Min | 5M Line Palo Alto FW Log | 881 | 129 | 0 | 2,358,226/Min | 5M Line Palo Alto FW Log (Clustered) | 881 | 129 | 612 | 972,425/Min |
The template strategy was originally proposed by a friend of mine in 2003 who later built a tool called never before seen (NBS) which also provides artificial ignorance for arbitrary text data as well as text structures.
Why use it?
I built this tool to solve a log analysis problem that I have suffered through while responding to many security breaches. Invariably, I need to find a needle in a haystack of log data. If you need to find a pattern that has not occurred previously, then this is the tool for you.More details can be found in the README file which is included in the distribution.
How to use it.
Templater has a simple command lines interface. In it's simplest form, pass a text file as an argument and the output will be list of counts and unique templates with the first full log line separated by a '||'.Including the first full log line with each unique template allows for quick recognition of the log lines that map to the unique template.
To get a list of all the options, you can execute the command with the -h or --help switch.
|
$ ./src/tmpltr --help tmpltr v0.5 [Jan 18 2012 - 01:45:11] syntax: tmpltr [options] filename [filename ...] -c|--cluster show invariable fields in output -d|--debug (0-9) enable debugging info -g|--greedy ignore quotes -h|--help this info -n|--cnum {num} Max cluster args [default: 1] -t|--templates {file} load templates to ignore -v|--version display version information -w|--write {file} save templates to file filename one or more files to process, use '-' to read from stdin |
The debug option is most useful when the tool is compiled with the --ENABLE-DEBUG switch.
A typical run of tmpltr is to pass the target log file as an argument and send the output through 'sort -n' to produce the following sorted list of unique templates and their frequency of occurent from least to most prevalent.
I normally go through the list in this order to speed up catching the anonlylous patterns.
|
% tmpltr /var/log/secure.log | sort -n Opening [/var/log/secure.log] for read 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %d %s %s %s:%s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_record_attribute_create_cfstring(): returned 2 attributes for dsAttrTypeStandard:AuthenticationAuthority 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %d %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Kerberos 5 refuses you 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s %s %s %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Failed to determine Kerberos principa name. 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_principal_for_user(): No authentication authority returned 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s()||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Done getpwnam() 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s, %s: %d %d||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Got euid, egid: 0 0 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s: %d %s %d||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in ac_complete(): ac_complete returned: 0 for 502 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s: (%s)||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Got ruser: (null) 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s - %s %s %s %s %s %d.||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_acct_mgmt(): OpenDirectory - Membership cache T L set to 1800. 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s: %s %s %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): pam_sm_setcred: krb5 user rdilley doesn't ha e a principal 7 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s: %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): pam_sm_setcred: ntlm done 8 %s %d %d:%d:%d %s %s[%d]: %s : %s=%s ; %s=/%s/%s/%s/%s/%s ; %s=%s ; %s=/%s/%s %s -%s//%s/%s/%s/%s||Dec 12 21:08:48 Rons-MacBook-Pro sudo[829]: root : TTY=unknown ; PWD /private/tmp/PKInstallSandbox.IDea5j/Scripts/com.apple.pkg.DeveloperToolsLeo.hfuS3V ; USER=root ; COMMAND=/bin/launchctl load -w //System/Library/LaunchDaemons/com.apple.docsetinstalld.pli t 8 %s %d %d:%d:%d %s %s[%d]: %s : %s=%s ; %s=/%s/%s/%s/%s/%s ; %s=%s ; %s=/%s/%s %s //%s/%s/%s/%s||Dec 12 20:51:54 Rons-MacBook-Pro sudo[1343]: root : TTY=unknown ; PWD=/ rivate/tmp/PKInstallSandbox.flT0Di/Scripts/com.apple.pkg.AppleMobileDeviceSupport.z2x5aw ; USER=root ; COMMAND=/bin/launchctl unload //System/Library/LaunchDaemons/com.apple.usbmuxd.plist 8 %s %d %d:%d:%d %s %s[%d]: %s %s||Dec 12 14:57:04 localhost com.apple.SecurityServer[24]: Entering service 14 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s() & %s()||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Done setegid() & seteuid() 14 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s: %d||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_principal_for_user(): failed: 7 14 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s: %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): pam_sm_authenticate: ntlm 17 %s %d %d:%d:%d %s %s[%d]: %s %d %s||Dec 12 14:57:03 localhost com.apple.SecurityServer[24]: Session 100000 created 18 %s %d %d:%d:%d %s %s[%d]: %s %s %s %s '%s' %s %s '%s' [%d] %s %s %s %s '%s' [%d]||Dec 12 20:50:11 Rons-MacBook-Pro com.apple.SecurityServer[24]: Failed to authorize right 'sys em.install.app-store-software' by client '/System/Library/PrivateFrameworks/PackageKit.framework/Versions/A/Resources/installd' [1158] for authorization created by '/System/Library/CoreSer ices/Software Update.app' [1129] 21 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s: %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Got user: rdilley 35 %s %d %d:%d:%d %s %s[%d]: %s %s(): %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Done cleanup3 74 %s %d %d:%d:%d: --- %s %s %s %d %s ---||Dec 12 20:48:18: --- last message repeated 1 time --- 3264 %s %d %d:%d:%d %s %s[%d]: %s %s %s '%s' %s %s '%s' [%d] %s %s %s %s '%s' [%d]||Dec 12 14:57:04 localhost com.apple.SecurityServer[24]: Succeeded authorizing right 'com.apple.S rviceManagement.daemons.modify' by client '/usr/libexec/UserEventAgent' [11] for authorization created by '/usr/libexec/UserEventAgent' [11] |
If the standard templating mode is obscuring too much information, you can switch to clustering mode (-c). This reduces the parsing speed, but allows the templates to retain all of the non-variable strings. I normally strip off the trailing example line when running in this mode just to keep the line length more managable. Below is an example of the same log processed with the clustering (-c) parsing option.
|
$ tmpltr -c /var/log/secure.log | sort -n Opening [/var/log/secure.log] for read 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in ac_complete(): ac_complete returned: 0 for 502||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in ac_complete(): ac_complete returned: 0 for 502 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in od_principal_for_user(): No authentication authority returned||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_principal_for_user(): No authentication authority returned 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in od_record_attribute_create_cfstring(): returned 2 attributes for dsAttrTypeStandard:AuthenticationAuthority||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_record_attribute_create_cfstring(): returned 2 attributes for dsAttrTypeStandard:AuthenticationAuthority 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_acct_mgmt(): OpenDirectory - Membership cache TTL set to 1800.||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_acct_mgmt(): OpenDirectory - Membership cache TTL set to 1800. 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_authenticate(): Failed to determine Kerberos principal name.||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Failed to determine Kerberos principal name. 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_authenticate(): Got ruser: (null)||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Got ruser: (null) 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_authenticate(): Kerberos 5 refuses you||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Kerberos 5 refuses you 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_setcred(): Done getpwnam()||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Done getpwnam() 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_setcred(): Got euid, egid: 0 0||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Got euid, egid: 0 0 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_setcred(): pam_sm_setcred: krb5 user rdilley doesn't have a principal||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): pam_sm_setcred: krb5 user rdilley doesn't have a principal 7 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_setcred(): pam_sm_setcred: ntlm done||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): pam_sm_setcred: ntlm done 8 Dec %d %d:%d:%d %s %s[%d]: %s %s||Dec 12 14:57:04 localhost com.apple.SecurityServer[24]: Entering service 8 Dec 12 %d:%d:%d Rons-MacBook-Pro sudo[%d]: root : TTY=unknown ; PWD=/private/tmp/%s/Scripts/%s ; USER=root ; COMMAND=/bin/launchctl %s //System/Library/LaunchDaemons/%s||Dec 12 20:51:54 Rons-MacBook-Pro sudo[1343]: root : TTY=unknown ; PWD=/private/tmp/PKInstallSandbox.flT0Di/Scripts/com.apple.pkg.AppleMobileDeviceSupport.z2x5aw ; USER=root ; COMMAND=/bin/launchctl unload //System/Library/LaunchDaemons/com.apple.usbmuxd.plist 8 Dec 12 21:%d:%d Rons-MacBook-Pro sudo[%d]: root : TTY=unknown ; PWD=/private/tmp/%s/Scripts/%s ; USER=%s ; COMMAND=/bin/launchctl load -w//System/Library/%s/%s||Dec 12 21:08:48 Rons-MacBook-Pro sudo[829]: root : TTY=unknown ; PWD=/private/tmp/PKInstallSandbox.IDea5j/Scripts/com.apple.pkg.DeveloperToolsLeo.hfuS3V ; USER=root ; COMMAND=/bin/launchctl load -w //System/Library/LaunchDaemons/com.apple.docsetinstalld.plist 14 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in %s(): %s: %d||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in od_principal_for_user(): failed: 7 14 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in %s(): %s: ntlm||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): pam_sm_authenticate: ntlm 14 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in pam_sm_setcred(): Done %s() & %s()||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_setcred(): Done setegid() & seteuid() 17 Dec %d %d:%d:%d %s com.apple.SecurityServer[24]: Session %d %s||Dec 12 14:57:03 localhost com.apple.SecurityServer[24]: Session 100000 created 18 Dec %d %d:%d:%d Rons-MacBook-Pro com.apple.SecurityServer[24]: Failed to authorize right '%s' by client '/System/Library/PrivateFrameworks/PackageKit.framework/Versions/A/Resources/installd' [%d] for authorization created by '%s' [%d]||Dec 12 20:50:11 Rons-MacBook-Pro com.apple.SecurityServer[24]: Failed to authorize right 'system.install.app-store-software' by client '/System/Library/PrivateFrameworks/PackageKit.framework/Versions/A/Resources/installd' [1158] for authorization created by '/System/Library/CoreServices/Software Update.app' [1129] 21 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in %s(): Got %s: %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Got user: rdilley 35 Dec %d %d:%d:%d Rons-MacBook-Pro authorizationhost[%d]: in %s(): %s %s||Dec 12 20:49:59 Rons-MacBook-Pro authorizationhost[1056]: in pam_sm_authenticate(): Done cleanup3 74 Dec %d %d:%d:%d: --- last message repeated %d %s ---||Dec 12 20:48:18: --- last message repeated 1 time --- 3264 Dec %d %d:%d:%d %s com.apple.SecurityServer[24]: Succeeded authorizing right '%s' by client '%s' [%d] for authorization created by '%s' [%d]||Dec 12 14:57:04 localhost com.apple.SecurityServer[24]: Succeeded authorizing right 'com.apple.ServiceManagement.daemons.modify' by client '/usr/libexec/UserEventAgent' [11] for authorization created by '/usr/libexec/UserEventAgent' [11] |
You can use the same syntax but also store copies of all of the unique templates by using the '-w {fname}' switch. When you do this, the file referenced with the switch is over written with a
The template file can be used with the '-t {fname}' switch to provide artificial ignorance capabilities.
|
% tmpltr -w ignore.templates /var/log/system.log | sort -n |
After the above run of the tool, a file named ignore.templates is created in the current directory as shown below:
|
% cat ignore.templates %s %d %d:%d:%d %s [%s].%s[%d]: [%s] [%s %s] %s %s %s %s %s://%s/%s/%s (%s %s %s %s://%s %s %s) %s %d %d:%d:%d %s %s[%d]: %s %s %s "%s" %s %d %d:%d:%d %s %s %s[%d]: %s: %s %s %d %s: %s %d %d:%d:%d %s %s[%d]: %s: %s - %s %d - %s %s %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %s - %s %s %s %s %s %s %d %d:%d:%d %s %s[%d]: %s %s %s %d %d:%d:%d %s %s[%d]: %s(%d.%d.%d.%d) (%s=%d): %s %s %s %s %s %d %d:%d:%d %s %s[%d]: %s %s %s/%s %s %s %s %s %s %s %d %d %s %d:%d:%d, %s %s %s %s %s %d %d %s %d:%d:%d %s %d %d:%d:%d %s %s[%d]: %s %s %s %d, %s %s %d %d:%d:%d %s %s[%d] (%s[%d]): %s %s %s %s: %d %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %s %s %d %d:%d:%d %s [%s].%s[%d]: %s %s, %s=-%d %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %s %s %s: /%s/%s/%s/%d.%d.%d.%s %s %d %d:%d:%d %s %s[%d]: %s %s %s %s (%s: %d) - %s %s:%d.%d, # %s %s: %d, # %s %s %s: %d, %s %s: %s, %s %s %s: %d, %s %s %s: %d %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %d %s %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %s: %s:/%s/%s/%s %s %d %d:%d:%d %s %s[%d]: %s %s %s %d %s %s %d %d:%d:%d %s %s[%d]: %s %s -%d.%d %c %s %d %d:%d:%d %s %s[%d]: %s: %s %s %s %d %d:%d:%d %s %s[%d] (%s): %s %s: %s %s %s %d %s %s %d %d:%d:%d %s %s[%d]: _%s: %s %s %s %s '%s' %s %d %d:%d:%d %s %s[%d]: %s: %s %s %s %s %s (%d.%d.%d.%d) %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s, %s:%d/%d/%d %d:%d:%d.%d %s - %s:%d/%d/%d %d:%d:%d.%d %s = %s:%d.%d %s %d %d:%d:%d %s %s[%d]: %s: %s %s %s %s %d %s %d %d:%d:%d %s %s[%d]: %s: %s - %s %d - %s %s %d %d:%d:%d %s [%s].%s[%d]: [%s] [%s %s] %s %s %s %s %s://%s/%s/%s (%s %s %s %s: %s %s) %s %d %d:%d:%d %s %s %s %s[%d]: %s %s %s %s (%s: %d) - %s %s:%d.%d, # %s %s: %d, # %s %s %s: %d, %s %s: %s, %s %s %s: %d, %s %s %s: %d %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %d %d:%d:%d %s %s[%d]: %s(%d.%d.%d.%d) (%s=%d): %s %s %s %s %d %d:%d:%d %s [%s].%s[%d]: %s %s %s %s %s %s %s - %s %s %s %s %s %s %s %s %d %d:%d:%d %s %s[%d]: %s %s %s: %s %s %d %d:%d:%d %s %s[%d]: %s %s, -%d %s %d %d:%d:%d: --- %s %s %s %d %s --- %s %d %d:%d:%d %s %s[%d]: %s %s %s %s %s %d %d:%d:%d %s %s[%d]: %s: %s %s %s %s %s %s |
You can now pass this file back into tmplptr and all log lines that match an existing template pattern will be ignored. This is the real utility of the tool. Using this teqnique, you can train tmpltr to ignore all log patterns that have been seen before and only show log templates for new patterns.
This is how I use to tool during incident repsonse. I push all the log data that I have for the period of my choice before the detected event into tmpltr and save the pattern file, then run tmpltr against the log data for the period around when the detected event happened.
|
% ./tmpltr -t ignore.templates /var/log/system.log |
A couple of things to note about the '-w' and '-t' switches:
If you use the '-w' switch in conjunction with the '-t', you should not read from and write to the same file. This version of tmpltr would allow you to do it without an issue if you pass the read '-t {fname}' arguments before the write '-w {fname}' arguments but future versions may not work as expected.
Additionally, when you load templates using the '-t' switch then write all the templates using the '-w' switch, then new file will contain all of the templates loaded from the template file as well as any new unique templates discovered in the processing of the log files. In this way, you can have your most recent saved template file always contain all of the templates that have been discovered.