From bca965e2ae33b2514b07dc04324b84288cd2339f Mon Sep 17 00:00:00 2001 From: Tony Murray Date: Wed, 9 Mar 2016 08:20:51 -0600 Subject: [PATCH 1/4] Some devices have "logging timestamp" enabled, try to remove that from the start of the message. Fixes #3199 --- includes/syslog.php | 9 ++++----- tests/SyslogTest.php | 8 ++++++++ 2 files changed, 12 insertions(+), 5 deletions(-) diff --git a/includes/syslog.php b/includes/syslog.php index 79e4b5b53..e0fae7bfc 100644 --- a/includes/syslog.php +++ b/includes/syslog.php @@ -54,12 +54,11 @@ function process_syslog($entry, $update) { if (in_array($os, array('ios', 'iosxe', 'catos'))) { // multipart message if(strpos($entry['msg'], ':') !== false) { - /* Split the following examples - * %CARD-SEVERITY-MSG:SLOT %FACILITY-SEVERITY-MNEMONIC: Message-text - * %FACILITY-SUBFACILITY-SEVERITY-MNEMONIC: Message-text - */ $matches = array(); - if(preg_match('/^(?%?[A-Za-z\d\-_]+(:[A-Z]* %[A-Z\d\-_]+)?): ?(?.*)/', $entry['msg'], $matches)) { + $timestamp_prefix = '([A-Z][a-z]{2} \d\d? \d\d:\d\d:\d\d(.\d\d\d [A-Z]{3})?: )?'; + $program_match = '(?%?[A-Za-z\d\-_]+(:[A-Z]* %[A-Z\d\-_]+)?)'; + $message_match = '(?.*)'; + if(preg_match('/^' . $timestamp_prefix . $program_match . ': ?' . $message_match . '/', $entry['msg'], $matches)) { $entry['program'] = $matches['program']; $entry['msg'] = $matches['msg']; } diff --git a/tests/SyslogTest.php b/tests/SyslogTest.php index 122489996..40c87e7c1 100644 --- a/tests/SyslogTest.php +++ b/tests/SyslogTest.php @@ -43,6 +43,14 @@ class SyslogTest extends \PHPUnit_Framework_TestCase "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC: Message-text||", array('device_id'=>1, 'program'=>'%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC', 'msg'=>'Message-text') ); + $testdata[] = $this->createData( + "1.1.1.1||local7||info||info||be||2016-03-09 03:58:25||Mar 9 11:58:24.145 UTC: %SEC-6-IPACCESSLOGS: list MNGMNT denied 120.62.186.12 1 packet ||]", + array('device_id'=>1, 'program'=>'%SEC-6-IPACCESSLOGS', 'msg'=>'list MNGMNT denied 120.62.186.12 1 packet') + ); + $testdata[] = $this->createData( + "1.1.1.1||local7||info||info||be||2016-04-27 021:12:28||Apr 27 21:12:28: %SYS-5-CONFIG_I: Configured from console by vty0||", + array('device_id'=>1, 'program'=>'%SYS-5-CONFIG_I', 'msg'=>'Configured from console by vty0') + ); // ---- CatOS ---- $testdata[] = $this->createData( From 33c4cca8a4ed127938653eeeca49e081e31e302b Mon Sep 17 00:00:00 2001 From: Tony Murray Date: Wed, 9 Mar 2016 08:43:39 -0600 Subject: [PATCH 2/4] Reduce memory cosumption for tests by running one assert at a time rather than building all the data then testing. --- tests/SyslogTest.php | 98 +++++++++++++++++++------------------------- 1 file changed, 42 insertions(+), 56 deletions(-) diff --git a/tests/SyslogTest.php b/tests/SyslogTest.php index 40c87e7c1..6c3b25c19 100644 --- a/tests/SyslogTest.php +++ b/tests/SyslogTest.php @@ -23,6 +23,19 @@ class SyslogTest extends \PHPUnit_Framework_TestCase return $data; } + + /** + * Test an input line with the modified fields + * + * @param string $inputline The line from the syslog daemon including the ||'s + * @param array $modified of the modified fields, most likely containging the keys program and msg + */ + private function checkSyslog($inputline, $modified) { + $data = $this->createData($inputline, $modified); + $res = process_syslog($data['input'], 0); + $this->assertEquals($data['result'], $res); + } + public function testCiscoSyslog() { // populate fake $dev_cache and $config @@ -31,67 +44,59 @@ class SyslogTest extends \PHPUnit_Framework_TestCase $config = array(); $config['syslog_filter'] = array(); - // populate test data - $testdata = array(); - // ---- IOS ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%CARD-SEVERITY-MSG:SLOT %FACILITY-SEVERITY-MNEMONIC: Message-text||", array('device_id'=>1, 'program'=>'%CARD-SEVERITY-MSG:SLOT %FACILITY-SEVERITY-MNEMONIC', 'msg'=>'Message-text') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC: Message-text||", array('device_id'=>1, 'program'=>'%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC', 'msg'=>'Message-text') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||local7||info||info||be||2016-03-09 03:58:25||Mar 9 11:58:24.145 UTC: %SEC-6-IPACCESSLOGS: list MNGMNT denied 120.62.186.12 1 packet ||]", array('device_id'=>1, 'program'=>'%SEC-6-IPACCESSLOGS', 'msg'=>'list MNGMNT denied 120.62.186.12 1 packet') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||local7||info||info||be||2016-04-27 021:12:28||Apr 27 21:12:28: %SYS-5-CONFIG_I: Configured from console by vty0||", array('device_id'=>1, 'program'=>'%SYS-5-CONFIG_I', 'msg'=>'Configured from console by vty0') ); + // ---- CatOS ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%IP-3-UDP_SOCKOVFL:UDP socket overflow||", array('device_id'=>1, 'program'=>'%IP-3-UDP_SOCKOVFL', 'msg'=>'UDP socket overflow') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||DTP-1-ILGLCFG: Illegal config (on, isl--on,dot1q) on Port [mod/port]||", array('device_id'=>1, 'program'=>'DTP-1-ILGLCFG', 'msg'=>'Illegal config (on, isl--on,dot1q) on Port [mod/port]') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||Cannot enable text mode config if ACL config is cleared from nvram||", array('device_id'=>1, 'program'=>'', 'msg'=>'Cannot enable text mode config if ACL config is cleared from nvram') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%PAGP-5-PORTFROMSTP / %PAGP-5-PORTTOSTP||", array('device_id'=>1, 'program'=>'%PAGP-5-PORTFROMSTP / %PAGP-5-PORTTOSTP') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%SYS-3-EOBC_CHANNELREINIT||", array('device_id'=>1, 'program'=>'%SYS-3-EOBC_CHANNELREINIT') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||%SYS-4-MODHPRESET:||", array('device_id'=>1, 'program'=>'%SYS-4-MODHPRESET', 'msg'=>'') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||InbandPingProcessFailure:Module x not responding over inband||", array('device_id'=>1, 'program'=>'INBANDPINGPROCESSFAILURE', 'msg'=>'Module x not responding over inband') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||RxSBIF_SEQ_NUM_ERROR:slot=x||", array('device_id'=>1, 'program'=>'RXSBIF_SEQ_NUM_ERROR', 'msg'=>'slot=x') ); - - // run tests - foreach($testdata as $data) { - $res = process_syslog($data['input'], 0); - $this->assertEquals($data['result'], $res); - } } public function testLinuxSyslog() { @@ -101,60 +106,51 @@ class SyslogTest extends \PHPUnit_Framework_TestCase $config = array(); $config['syslog_filter'] = array(); - // populate test data - $testdata = array(); - // ---- PAM ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||authpriv||info||info||56||2016-02-28 00:23:34||pam_unix(cron:session): session opened for user librenms by (uid=0)||CRON", array('device_id'=>1, 'program'=>'PAM_UNIX(CRON:SESSION)', 'msg'=>'session opened for user librenms by (uid=0)') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||authpriv||info||info||55||2016-02-28 00:23:34||pam_unix(sudo:session): session opened for user librenms by root (uid=0)||sudo", array('device_id'=>1, 'program'=>'PAM_UNIX(SUDO:SESSION)', 'msg'=>'session opened for user librenms by root (uid=0)') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||auth||info||info||0e||2016-02-28 00:23:34||pam_krb5(sshd:auth): authentication failure; logname=root uid=0 euid=0 tty=ssh ruser= rhost=123.213.132.231||sshd", array('device_id'=>1, 'program'=>'PAM_KRB5(SSHD:AUTH)', 'msg'=>'authentication failure; logname=root uid=0 euid=0 tty=ssh ruser= rhost=123.213.132.231') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||auth||info||info||0e||2016-02-28 00:23:34||pam_krb5[sshd:auth]: authentication failure; logname=root uid=0 euid=0 tty=ssh ruser= rhost=123.213.132.231||sshd", array('device_id'=>1, 'program'=>'PAM_KRB5[SSHD:AUTH]', 'msg'=>'authentication failure; logname=root uid=0 euid=0 tty=ssh ruser= rhost=123.213.132.231') ); // ---- Postfix ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||mail||info||info||16||2016-02-28 00:23:34||5C62E329EF: to=, relay=mail.example.com[127.0.0.1]:25, delay=0.11, delays=0.04/0.01/0/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5362E6A670E)||postfix/smtp", array('device_id'=>1, 'program'=>'POSTFIX/SMTP', 'msg'=>'5C62E329EF: to=, relay=mail.example.com[127.0.0.1]:25, delay=0.11, delays=0.04/0.01/0/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5362E6A670E)') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||mail||info||info||16||2016-02-28 00:23:34||D7256400EF: from=, size=882, nrcpt=1 (queue active)||postfix/qmgr", array('device_id'=>1, 'program'=>'POSTFIX/QMGR', 'msg'=>'D7256400EF: from=, size=882, nrcpt=1 (queue active)') ); // ---- No program ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||some random message||", array('device_id'=>1, 'program'=>'USER', 'msg'=>'some random message') ); // ---- Other ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||cron||info||info||4e||2016-02-28 00:23:34||(librenms) CMD ( /opt/librenms/alerts.php >> /var/log/librenms_alert.log 2>&1)||CRON", array('device_id'=>1, 'program'=>'CRON', 'msg'=>'(librenms) CMD ( /opt/librenms/alerts.php >> /var/log/librenms_alert.log 2>&1)') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||authpriv||notice||notice||55||2016-02-28 00:23:34|| root : TTY=pts/1 ; PWD=/opt/librenms ; USER=librenms ; COMMAND=/usr/bin/git status||sudo", array('device_id'=>1, 'program'=>'SUDO', 'msg'=>'root : TTY=pts/1 ; PWD=/opt/librenms ; USER=librenms ; COMMAND=/usr/bin/git status') ); - - - // run tests - foreach($testdata as $data) { - $res = process_syslog($data['input'], 0); - $this->assertEquals($data['result'], $res); - } } + public function testProcurveSyslog() { // populate fake $dev_cache and $config @@ -163,43 +159,33 @@ class SyslogTest extends \PHPUnit_Framework_TestCase $config = array(); $config['syslog_filter'] = array(); - // populate test data - $testdata = array(); - // ---- 2900/2910/3800/5400 ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||chassis: Slot A Ready||00422", array('device_id'=>1, 'program'=>'CHASSIS', 'msg'=>'Slot A Ready [00422]') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||ports: port 21 is now on-line||00076", array('device_id'=>1, 'program'=>'PORTS', 'msg'=>'port 21 is now on-line [00076]') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||ports: port 21 is now off-line||00077", array('device_id'=>1, 'program'=>'PORTS', 'msg'=>'port 21 is now off-line [00077]') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||warning||warning||0c||2016-02-28 00:23:34||FFI: port 21-High collision or drop rate. See help.||00331", array('device_id'=>1, 'program'=>'FFI', 'msg'=>'port 21-High collision or drop rate. See help. [00331]') ); // ---- 2610 ---- - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||warning||warning||0c||2016-02-28 00:23:34||port 21-Excessive undersized/giant packets. See help.||FFI", array('device_id'=>1, 'program'=>'FFI', 'msg'=>'port 21-Excessive undersized/giant packets. See help.') ); - $testdata[] = $this->createData( + $this->checkSyslog( "1.1.1.1||user||info||info||0e||2016-02-28 00:23:34||updated time by -4 seconds||SNTP", array('device_id'=>1, 'program'=>'SNTP', 'msg'=>'updated time by -4 seconds') ); - - - // run tests - foreach($testdata as $data) { - $res = process_syslog($data['input'], 0); - $this->assertEquals($data['result'], $res); - } } } From d59fc01b61a9f25bc97c805b60edb8f1cd9bac4e Mon Sep 17 00:00:00 2001 From: Tony Murray Date: Wed, 9 Mar 2016 10:49:12 -0600 Subject: [PATCH 3/4] Another test case for the cisco syslog timestamp prefix. --- includes/syslog.php | 2 +- tests/SyslogTest.php | 4 ++++ 2 files changed, 5 insertions(+), 1 deletion(-) diff --git a/includes/syslog.php b/includes/syslog.php index e0fae7bfc..395e13a7a 100644 --- a/includes/syslog.php +++ b/includes/syslog.php @@ -55,7 +55,7 @@ function process_syslog($entry, $update) { // multipart message if(strpos($entry['msg'], ':') !== false) { $matches = array(); - $timestamp_prefix = '([A-Z][a-z]{2} \d\d? \d\d:\d\d:\d\d(.\d\d\d [A-Z]{3})?: )?'; + $timestamp_prefix = '([A-Z][a-z]{2} \d\d? \d\d:\d\d:\d\d(.\d\d\d)?( [A-Z]{3})?: )?'; $program_match = '(?%?[A-Za-z\d\-_]+(:[A-Z]* %[A-Z\d\-_]+)?)'; $message_match = '(?.*)'; if(preg_match('/^' . $timestamp_prefix . $program_match . ': ?' . $message_match . '/', $entry['msg'], $matches)) { diff --git a/tests/SyslogTest.php b/tests/SyslogTest.php index 6c3b25c19..a3c979767 100644 --- a/tests/SyslogTest.php +++ b/tests/SyslogTest.php @@ -61,6 +61,10 @@ class SyslogTest extends \PHPUnit_Framework_TestCase "1.1.1.1||local7||info||info||be||2016-04-27 021:12:28||Apr 27 21:12:28: %SYS-5-CONFIG_I: Configured from console by vty0||", array('device_id'=>1, 'program'=>'%SYS-5-CONFIG_I', 'msg'=>'Configured from console by vty0') ); + $this->checkSyslog( + "1.1.1.1||local7||info||info||be||2016-04-27 021:12:28||Mar 8 20:14:08.762: %FACILITY-SUBFACILITY-SEVERITY-MNEMONIC: Message-text||000956", + array('device_id'=>1, 'program'=>'%FACILITY-SUBFACILITY-SEVERITY-MNEMONIC', 'msg'=>'Message-text') + ); // ---- CatOS ---- From 81a626713ad24548e4e7825bc36a1915b8b16d6e Mon Sep 17 00:00:00 2001 From: Tony Murray Date: Wed, 9 Mar 2016 14:31:00 -0600 Subject: [PATCH 4/4] Fix indentation. --- tests/SyslogTest.php | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/tests/SyslogTest.php b/tests/SyslogTest.php index a3c979767..5336a4494 100644 --- a/tests/SyslogTest.php +++ b/tests/SyslogTest.php @@ -25,11 +25,11 @@ class SyslogTest extends \PHPUnit_Framework_TestCase /** - * Test an input line with the modified fields - * - * @param string $inputline The line from the syslog daemon including the ||'s - * @param array $modified of the modified fields, most likely containging the keys program and msg - */ + * Test an input line with the modified fields + * + * @param string $inputline The line from the syslog daemon including the ||'s + * @param array $modified of the modified fields, most likely containging the keys program and msg + */ private function checkSyslog($inputline, $modified) { $data = $this->createData($inputline, $modified); $res = process_syslog($data['input'], 0);