From 077e8fa986e587b837ac15bb3def217422ecfe4d Mon Sep 17 00:00:00 2001 From: Christian Herdtweck Date: Tue, 8 Nov 2022 11:37:09 +0100 Subject: [PATCH] Add 3 unittests with fixed log file contents Add some stability/reliability/reproducability to log parsing unit tests. Also: fix type documentation in LogParser doc string --- src/log_read.py | 5 +- test/test_log_read.py | 99 +++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 102 insertions(+), 2 deletions(-) diff --git a/src/log_read.py b/src/log_read.py index ca47eb9..eeca819 100644 --- a/src/log_read.py +++ b/src/log_read.py @@ -363,8 +363,9 @@ class LogParser(LineReader): """ Create a LogParser. - :param str log_file: name of log file to parse (required!) - :param pattern: regexp to split log lines; None (default) to return + :param log_file: source of log lines to parse + :type log_file: see arg `sources` of constructor of :py:class:`IterativeReader` + :param pattern: regexp to parse log lines; None (default) to return line as they are :type pattern: str or None (default) """ diff --git a/test/test_log_read.py b/test/test_log_read.py index 68c9160..d994971 100644 --- a/test/test_log_read.py +++ b/test/test_log_read.py @@ -257,6 +257,105 @@ class LogReadTester(unittest.TestCase): line_read)) self.assertEqual(line_expected, line_read) + def test_parse_syslog_lines(self): + """Test parsing a few fixed lines of syslog""" + syslog_lines = """ + Nov 8 08:10:01 system-name rsyslogd: [origin software="rsyslogd" swVersion="8.39.0" x-pid="1968" x-info="http://www.rsyslog.com"] rsyslogd was HUPed + Nov 8 08:10:12 system-name squid[2762]: Starting new redirector helpers...#012 current master transaction: master58 + Nov 8 08:10:28 system-name pop30[3922]: counts: retr=<0> top=<0> dele=<0> + Nov 8 08:10:43 system-name pop3loc[3923]: counts: retr=<0> top=<0> dele=<0> + Nov 8 08:10:44 system-name pingcheck[3004]: Status (0 down, limit=4, notify up now): report link up? + Nov 8 08:10:44 system-name connd[2917]: [subsys_pingcheck] received notification that connection for id 1 is online + Nov 8 08:10:44 system-name connd[2917]: [subsys_pingcheck] Connection [ConnInfo P1 (connection name): online] was confirmed online + Nov 8 08:10:44 system-name connd[2917]: [connection_manager] Confirm that provider "P1" is online + Nov 8 08:11:01 system-name mon[3563]: failure for intranator dirwatchd 1667891461 (NO SUMMARY) + Nov 8 08:11:04 system-name lmtpunix[3962]: Delivered: to mailbox: user.cyrus as uid: 49792 + Nov 8 08:11:04 system-name lmtpunix[3962]: USAGE cyrus user: 0.000000 sys: 0.006803 + Nov 8 08:11:20 system-name pop30[3982]: counts: retr=<0> top=<0> dele=<0> + Oct 21 07:52:39 system-name avupdate[3671]: successfully installed new antivirus database + Oct 21 07:52:39 system-name savapi_version_info[3973]: AVE=8.3.64.214, VDF=8.19.26.110, Released=21.10.2022 05:39 + Oct 21 07:52:39 system-name connd[3180]: [connection_manager] online mode set to always online + Oct 21 07:52:47 system-name kernel: REJECT local IN=eth0 OUT= MACSRC=68:4f:64:75:7b:82 MACDST=01:00:5e:00:00:01 MACPROTO=0800 SRC=123.45.67.89 DST=224.0.0.1 LEN=36 TOS=0x00 PREC=0x00 TTL=1 ID=34431 PROTO=ICMP TYPE=9 CODE=0 + Oct 21 07:52:54 system-name lmtpunix[2715]: Delivered: to mailbox: user.cyrus as uid: 46558 + Oct 21 07:52:54 system-name lmtpunix[2715]: USAGE cyrus user: 0.010564 sys: 0.000000 + Oct 21 07:53:08 system-name pop30[2703]: counts: retr=<0> top=<0> dele=<0> + Oct 21 07:53:08 system-name pop3loc[2701]: counts: retr=<0> top=<0> dele=<0> + Oct 21 07:53:30 system-name ntpd[3701]: adjusting local clock by -0.943974s + Oct 21 07:54:15 system-name keymakerd[3206]: [acmeautorenew] Starting auto renew check. @acmeautorenew#285 + Oct 21 07:54:15 system-name keymakerd[3206]: [acmeautorenew] Finishing auto renew thread. @acmeautorenew#206 + Oct 21 07:54:23 system-name pop3loc[2701]: counts: retr=<0> top=<0> dele=<0> + Oct 21 07:54:41 system-name pop30[2703]: counts: retr=<0> top=<0> dele=<0> + Oct 21 07:54:51 system-name squid[3025]: Starting new redirector helpers...#012 current master transaction: master54 + Oct 21 07:54:55 system-name lmtpunix[3997]: Delivered: to mailbox: user.cyrus as uid: 46559 + Oct 21 07:54:55 system-name lmtpunix[3997]: USAGE cyrus user: 0.002022 sys: 0.005926 + """ + lines = [line.lstrip() for line in syslog_lines.splitlines() if line.lstrip()] + LogFileWriter(self.temp_file, lines, n_writes=len(lines)).start() + with open(self.temp_file, 'rt') as file_handle: + parser = LogParser(file_handle, SYS_LOG_PATTERN) + for _, data, _ in parser: + self.assertIsNotNone(data, f"Failed to parse {parser.last_unparsed_line}") + + def test_parse_proxy_lines(self): + proxy_lines = """ + 1667901672.645 0 127.0.0.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + 1667901792.812 0 127.0.0.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + 1667901912.997 0 127.0.0.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + 1667902032.168 0 127.0.0.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + 1667902055.130 571 192.168.1.1 TCP_TUNNEL/200 10403 CONNECT apod.nasa.gov:443 - HIER_DIRECT/apod.nasa.gov - - + 1667902063.333 969 192.168.1.1 TCP_TUNNEL/200 174425 CONNECT www.startpage.com:443 - HIER_DIRECT/www.startpage.com - - + 1667902063.352 17 192.168.1.1 TCP_TUNNEL/200 39 CONNECT www.startpage.com:443 - HIER_DIRECT/www.startpage.com - - + 1667902063.539 24 192.168.1.1 TCP_TUNNEL/200 39 CONNECT www.startpage.com:443 - HIER_DIRECT/www.startpage.com - - + 1667902063.545 207 192.168.1.1 TCP_TUNNEL/200 1720 CONNECT www.startpage.com:443 - HIER_DIRECT/www.startpage.com - - + 1667902064.141 611 192.168.1.1 TCP_TUNNEL/200 10100 CONNECT www.startpage.com:443 - HIER_DIRECT/www.startpage.com - - + 1667902072.816 974 192.168.1.1 TCP_MISS/200 981 POST http://r3.o.lencr.org/ - FIRSTUP_PARENT/127.0.0.1 application/ocsp-response - + 1667902089.338 16331 192.168.1.1 TCP_TUNNEL/200 103739 CONNECT www.roma-pizza-tuebingen.de:443 - HIER_DIRECT/www.roma-pizza-tuebingen.de - - + 1667902089.339 16332 192.168.1.1 TCP_TUNNEL/200 49795 CONNECT www.roma-pizza-tuebingen.de:443 - HIER_DIRECT/www.roma-pizza-tuebingen.de - - + 1667902089.339 16330 192.168.1.1 TCP_TUNNEL/200 24641 CONNECT www.roma-pizza-tuebingen.de:443 - HIER_DIRECT/www.roma-pizza-tuebingen.de - - + 1667902105.718 0 192.168.1.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + 1667902152.347 0 127.0.0.1 NONE_NONE/000 0 - error:transaction-end-before-headers - HIER_NONE/- - - + """ + lines = [line.lstrip() for line in proxy_lines.splitlines() if line.lstrip()] + LogFileWriter(self.temp_file, lines, n_writes=len(lines)).start() + with open(self.temp_file, 'rt') as file_handle: + parser = LogParser(file_handle, PROXY_LOG_PATTERN) + for _, data, _ in parser: + self.assertIsNotNone(data, f"Failed to parse {parser.last_unparsed_line}") + + def test_parse_maillog_lines(self): + mail_lines = """ + Nov 7 10:07:33 system-name amavis[1]: SA info: rules: meta test I2N_RAZOR_ADJUST_4 has dependency 'RAZOR2_CF_RANGE_E8_51_100' with a zero score + Nov 7 10:07:33 system-name amavis[1]: SpamControl: init_pre_fork on SpamAssassin done + Nov 7 10:07:35 system-name quarantined[3574]: quarantined version 0.15 (build Jun 28 2022 17:26:39) up and running + Nov 7 10:07:52 system-name mailreconfig[3713]: called by sh[3712]|generate[3663], mode update, changed files: aliases,recipients + Nov 7 10:07:53 system-name postfix/postfix-script[3724]: refreshing the Postfix mail system + Nov 7 10:07:53 system-name postfix/master[2548]: reload -- version 3.3.22, configuration /etc/postfix + Nov 7 10:08:07 system-name mailreconfig[3851]: called by sh[3850]|generate[3804], mode update, changed files: aliases,recipients + Nov 7 10:08:07 system-name postfix/postfix-script[3862]: refreshing the Postfix mail system + Nov 7 10:08:07 system-name postfix/master[2548]: reload -- version 3.3.22, configuration /etc/postfix + Nov 7 10:08:11 system-name postfix/smtpd[3933]: connect from system-name.net.lan[127.0.0.1] + Nov 7 10:08:11 system-name postfix/smtpd[3933]: D9C626B: client=system-name.net.lan[127.0.0.1] + Nov 7 10:08:11 system-name postfix/cleanup[3936]: D9C626B: message-id=<20221107090811.D9C626B@system-name.net.lan> + Nov 7 10:08:11 system-name postfix/qmgr[3868]: D9C626B: from=, size=10888, nrcpt=1 (queue active) + Nov 7 10:08:11 system-name postfix/smtpd[3933]: disconnect from system-name.net.lan[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 + Nov 7 10:08:11 system-name postfix/smtpd[3933]: connect from system-name.net.lan[127.0.0.1] + Nov 7 10:08:11 system-name postfix/smtpd[3933]: E59146D: client=system-name.net.lan[127.0.0.1] + Nov 7 10:08:11 system-name postfix/cleanup[3936]: E59146D: message-id=<20221107090811.E59146D@system-name.net.lan> + Nov 7 10:08:11 system-name amavis[11]: (00011-01) LMTP::10024 /var/spool/vscan/amavis/tmp/amavis-20221107T100811-00011: -> SIZE=10888 Received: from system-name.net.lan ([127.0.0.1]) by localhost (system-name.net.lan [127.0.0.1]) (amavisd-new, port 10024) with LMTP for ; Mon, 7 Nov 2022 10:08:11 +0100 (CET) + Nov 7 10:08:12 system-name postfix/qmgr[3868]: E59146D: from=, size=9472, nrcpt=1 (queue active) + Nov 7 10:08:12 system-name postfix/smtpd[3933]: disconnect from system-name.net.lan[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 + Nov 7 10:08:12 system-name postfix/smtpd[3933]: connect from system-name.net.lan[127.0.0.1] + Nov 7 10:08:12 system-name amavis[11]: (00011-01) Checking: q4eVqFn169Kq [127.0.0.1] -> + Nov 7 10:08:12 system-name amavis[11]: (00011-01) p.path BANNED:1 test-recipient@system-name.net.lan: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/x-msdownload,T=exe,T=exe-ms,N=cloudcar.exe", matching_key="(?^i:\\.exe$)" + Nov 7 10:08:12 system-name postfix/qmgr[3868]: 4B0CF70: from=, size=164391, nrcpt=1 (queue active) + """ + lines = [line.lstrip() for line in mail_lines.splitlines() if line.lstrip()] + LogFileWriter(self.temp_file, lines, n_writes=len(lines)).start() + with open(self.temp_file, 'rt') as file_handle: + parser = LogParser(file_handle, SYS_LOG_PATTERN) + for _, data, _ in parser: + self.assertIsNotNone(data, f"Failed to parse {parser.last_unparsed_line}") + @unittest.skipIf(not os.access('/var/log/messages', os.R_OK), "messages not accessible") def test_parse_messages(self): -- 1.7.1