log2timeline / plaso

Super timeline all the things
https://plaso.readthedocs.io
Apache License 2.0
1.73k stars 349 forks source link

Issues parsing *nix image - syslog errors, OS detection, Worker processing untracked task #924

Closed ghost closed 8 years ago

ghost commented 8 years ago

1.5 RC1 Ubuntu 14.04LTS 64 bit

Testing RC1 against victoria-v8.sda1.img from a Honeynet forensics challenge here: https://www.honeynet.org/challenges/2011_7_compromised_server

Syslog parser generates thousands of errors saying it cannot parse log lines. Also OS type is not identified in preprocessing. (User accounts are correctly parsed from /etc/passwd and hostname is parsed, so preprocessing should be able to do better than 'N/A' for OS, OS Product & OS Version). Also errors in log file re worker processing untracked task.

# wget http://www.honeynet.org/challenge2011/downloads/victoria-v8.sda1.img.zip
# unzip victoria-v8.sda1.img.zip
  (See below for why I loop mount/fsck - not relevant to issue report)
# losetup /dev/loop0 victoria-v8.sda1.img
# fsck -y /dev/loop0
# losetup -d /dev/loop0
# losetup -r /dev/loop0 victoria-v8.sda1.img
# mount /dev/loop0 /mnt/victoria -o ro
# log2timeline.py --hashers all --process_archives --debug --logfile X.log --workers 20 victoria2.plaso 
victoria-v8.sda1.img

Processing completed.
Number of errors encountered while extracting events: 2990.

Use pinfo to inspect errors in more detail.

# pinfo.py -v victoria2.plaso

***************************** System configuration *****************************
                Hostname : victoria
        Operating system : N/A
Operating system product : N/A
Operating system version : N/A
               Code page : cp1252
         Keyboard layout : N/A
               Time zone : UTC
--------------------------------------------------------------------------------

******************************** User accounts *********************************
       sync : /bin
      gnats : /var/lib/gnats
     pepito : /home/pepito
       uucp : /var/spool/uucp
      statd : /var/lib/nfs
         lp : /var/spool/lpd
...

****** Events generated per parser: b28ffb65-0db5-4b59-b56b-12d3a6734f5c *******
Parser (plugin) name : Number of events
--------------------------------------------------------------------------------
            filestat : 72956
             hachoir : 1
                  pe : 2
              syslog : 6180
               Total : 79139
--------------------------------------------------------------------------------

************************* Events generated per parser **************************
Parser (plugin) name : Number of events
--------------------------------------------------------------------------------
            filestat : 72956
             hachoir : 1
                  pe : 2
              syslog : 6180
               Total : 79139
--------------------------------------------------------------------------------

*********************************** Error: 0 ***********************************
           Message : Unable to parse log line: u'Feb 6 15:16:30 victoria
                     sshd[2085]: pam_unix(sshd:auth): check pass; user un...'
      Parser chain : syslog
Path specification : type: OS, location:
                     /root/timestamp_test/victoria-v8.sda1.img
                   : type: RAW
                   : type: TSK, inode: 8296, location: /var/log/auth.log
--------------------------------------------------------------------------------

*********************************** Error: 1 ***********************************
           Message : Unable to parse log line: u'Feb 6 15:16:32 victoria
                     sshd[2085]: Failed password for invalid user ulysses...'
      Parser chain : syslog
Path specification : type: OS, location:
                     /root/timestamp_test/victoria-v8.sda1.img
                   : type: RAW
                   : type: TSK, inode: 8296, location: /var/log/auth.log
--------------------------------------------------------------------------------

*********************************** Error: 2 ***********************************
           Message : Unable to parse log line: u'Feb 6 15:16:37 victoria
                     sshd[2085]: pam_unix(sshd:auth): check pass; user un...'
      Parser chain : syslog
Path specification : type: OS, location:
                     /root/timestamp_test/victoria-v8.sda1.img
                   : type: RAW
                   : type: TSK, inode: 8296, location: /var/log/auth.log
--------------------------------------------------------------------------------

*********************************** Error: 3 ***********************************
           Message : Unable to parse log line: u'Feb 6 15:16:40 victoria
                     sshd[2085]: Failed password for invalid user ulysses...'
      Parser chain : syslog
Path specification : type: OS, location:
                     /root/timestamp_test/victoria-v8.sda1.img
                   : type: RAW
                   : type: TSK, inode: 8296, location: /var/log/auth.log
--------------------------------------------------------------------------------

*********************************** Error: 4 ***********************************
           Message : Unable to parse log line: u'Feb 6 15:16:40 victoria
                     sshd[2085]: PAM 2 more authentication failures; logn...'
      Parser chain : syslog
Path specification : type: OS, location:
                     /root/timestamp_test/victoria-v8.sda1.img
                   : type: RAW
                   : type: TSK, inode: 8296, location: /var/log/auth.log
--------------------------------------------------------------------------------

# grep ERROR victoria.log

2016-08-14 16:32:30,273 [ERROR] (MainProcess) PID:4482 <task_engine> Worker processing untracked task: 02634e9098c242c1afa7341adb00ae83.
2016-08-14 16:36:11,318 [ERROR] (MainProcess) PID:4482 <task_engine> Worker processing untracked task: d6b7cb74589942f3a5bcdae165468d88.
2016-08-14 16:37:19,049 [ERROR] (MainProcess) PID:4482 <task_engine> Worker processing untracked task: ba99f4484c7a48fa88769f7c94c1f40f.

victoria.log.gz auth.log.gz

Note: The file system in the img file is unclean (needs fsck). The objective of my test was to compare timestamps parsed by l2t with those parsed by Linux, which required that I mount the fs (ro). Therefore I had to 'fsck -y' it first.

ghost commented 8 years ago

And preprocessing gets the timezone of the image wrong too. /etc/timezone is "Europe/Paris" but preprocessing says UTC.

Onager commented 8 years ago

There are a few issues here, so I'll create issues for each of them. One thing I notice right away is apparently at some point syslog logged as "Feb 6" rather than "Feb 06". I'll tweak the parser.

Onager commented 8 years ago

Closing this issue out in favour for #928 #929 and #930.