Log Management:
Monitoring and Making Sense of Logs

License

This work by Z. Cliffe Schreuders and updated by Gary Roper at Leeds Beckett University is licensed under a Creative Commons Attribution-ShareAlike 3.0 Unported License.

Contents

License

Contents

Preparation

An Introduction to systemd

Journald Basics

Syslog basics

Watching for file changes

Writing to Syslog from the commandline

Understanding Syslog

Writing Syslog configuration rules

Network logging

Logrotate

Command history

Regular expressions

Windows and Logs

Unguided Problem-based tasks

Preparation

These tasks can be completed on a recent openSUSE VM on oVirt or VMware. This lab could be completed on most modern Linux systems with systemd.  However, if you are not using an openSUSE distro of Linux, the config files may vary slightly.

An Introduction to systemd

Until recently, most Linux systems used text based log files for everything but this has changed recently due to the introduction of systemd.  Systemd is a suite of tools responsible for starting and managing a system and its services. It replaces the old init system and does much more.  

Systemd provides a new system for collecting and monitoring logs called journal. The journald daemon handles all messages produced by the kernel, services, etc. and stores them together in a binary format that can be easily and quickly manipulated.

The journalctl command is provided to manipulate and interrogate the logs but first let’s look at the basic units of management used by systemd.  The systemctl command is provided to enable a systemd controlled machine to manage services.

Start the ssh service with the following command:

        sudo systemctl start sshd

Check the status of the ssh service with the following command:

        sudo systemctl status sshd

Restart the ssh service with minimal disruption using the following command:

        sudo systemctl restart sshd

Stop the ssh service using the the following command.

        sudo systemctl stop sshd

Check the status of the ssh service to confirm that it has been stopped with the following command:

        sudo systemctl status sshd

The ssh service can be told to start at boot time with the following command:

        sudo systemctl enable sshd

The systemctl command can be used to shutdown or restart a machine “poweroff” or “reboot”.  Use the following command to reboot the VM and to prove that the ssh service now runs at boot up:

        sudo systemctl reboot

Once the VM has rebooted, check the status of the ssh service to confirm that it started when the machine booted with the following command:

        sudo systemctl status sshd

Use the following command to stop the ssh service starting at boot time.

        sudo systemctl disable sshd

Journald Basics

The journalctl command is provided to search and manipulate the journal log files that are managed and updated by journald.  View the whole of the log contents with the following command.

        sudo journalctl

You should have noticed that journald displayed all the log information using the less pager command.  The paging facility can be disabled using the --no-pager switch.  You may need to use this switch if want to send the output of the journalctl command to a file or another process.  Use the --no-pager switch to compare how much information is provided to the root superuser compared to a normal user.

        journalctl --no-pager > journaluser.txt

sudo journalctl --no-pager > journalroot.txt

        ls -lh

Compare the file sizes in the output from ls. You should have noticed that much more information is provided to the root superuser than an ordinary user who has much less permission on the system.

You may have noticed that the contents of the logs are displayed with the earliest date first and the most recent last.  This can be reversed using the “-r” or “--reverse” switches as follows.

 sudo journalctl -r

Another useful switch is the “-n” or “--lines=” switch were we can tell jounalctl to list the n most recent messages.  Use the following command to list the 20 most recent messages:

sudo journalctl -n 20

A time range can be used to reduce the amount of information displayed by journalctl.  Use the following command to list all log information generated today (since 00:00:00).

        sudo journalctl --since today

Use the following command to display all the log information generated yesterday and today (from yesterday at 00:00:00 until now):

        sudo journalctl --since yesterday

Use the following command to display all the log information generated any time on 18 September 2016 (Help: adjust the date to suit your data if required to get output):

sudo journalctl --since "2016-09-18 00:00:00" --until "2016-09-18 23:59:59"

Use the following command to display all the log information generated this boot:

sudo journalctl -b

Use the following command to display all the log information generated in the last boot:

        sudo journalctl -b -1

Use the following command to list every time the machine was booted:

        sudo journalctl --list-boots

Use the following command to list all the log entries for a particular service:

        sudo journalctl -u sshd

Use the following command to filter log entries by service and a time range:

        sudo journalctl -u sshd --since today

Use the “-k” or “--dmesg” switches to find log messages about the kernel:

        sudo journalctl -k

Display kernel log messages from the previous boot with the following command:

sudo journalctl -k -b -2

Journalctl can be used to list all messages generated by a process id number as follows.  Use the ps or ps aux command to find a process on your system and use the following command to find any messages generated by that process.

sudo journalctl _PID=your_procees_id_number

Journal entries can be filtered by message priority, e.g. the following command will list all error messages since the system was last booted.

        sudo journalctl -p err -b                


Help: if you get no error messages, try the above command without the “-b” to show all logged error messages on the system.


The following priorities may be used to filter in place of “err”.  The priority number can also be used after the “-p” switch.

You can also revert to the old methods of searching log files by using journalctl to list the full log contents and piping the output to another commands such as grep.  

List all the attempts to gain root privileges with the following command:

        sudo journalctl --no-pager | grep "to root"

List just the failed attempts to gain root privileges:

sudo journalctl --no-pager | grep "FAILED SU (to root)"


Help: if you get no output from the previous command, run any command using sudo and type the wrong password.  Then run the previous command again.

It is sometimes very helpful to use the “-f” or “--follow” switches which show only the most recent journal entries, and continuously print new entries as they are added to the journal.

sudo journalctl -f                                                 

Open another terminal and run sudo with any command to generate some log messages, e.g. the following command should do it:

        sudo ls

In the terminal where the sudo “journalctl -f” command is running:

        Press Ctl+Z to quit (Help: Ctl+C if this fails)

Syslog basics

Syslog uses the traditional methods of storing log messages in separate log files.  Syslog is still used today on many legacy systems and modern Linux systems that interact with legacy systems.  A popular version of syslog is called rsyslog and can be used in conjunction with journald on modern systems.

Install rsyslog on your system using the following command:

sudo zypper install rsyslog

Help: with the installing rsyslog, you will very likely get the following warning message when you install rsylog on an openSUSE VM.  Choose option 1 to uninstall the systemd-logger.

Use the following command to start the rsyslog service when it has installed.

sudo systemctl start rsyslog

Use the following command to ensure start that the rsyslog service starts when the system is booted.

sudo systemctl start rsyslog

Open a terminal console (such as Konsole from KDEMenu → System → Terminal → Konsole).

Start by having a look at the logs that are available on a Unix/Linux system. These are typically stored in /var/log.

List the various log files by running:

tree /var/log

(Help: if you do not have the command “tree” installed, use the following command to install it: sudo zypper install tree)

Have a look through the various files present, and try to identify the purpose of as many as possible. You may wish to open these using “less /var/log/”... followed by a filename.

Hint: try typing “less /var/log/” then without pressing enter, press TAB twice, this will list all the files in /var/log that you could complete the command argument with.

Depending on the version of Unix or distribution of Linux you are using, and the system’s configuration, there will be slightly different log files present. Most Unix systems will have a /var/log/messages file (or /var/log/syslog), which is the main location for various logs received by Syslog (and newer Syslog replacements such as Rsyslog). Syslog-like loggers are one of the most common log mechanisms deployed.

Note: you should notice a journal directory that is used to hold the files maintained by the journald service.  Journald will rotate (compress and archive) old data as instructed in its configuration file.  Journald has been deliberately designed to work in parallel with syslog on the same system until the transition to journald is complete.

View the contents of your messages log file:

sudo less /var/log/messages

(press ‘q’ to exit, when you are done)

Depending on how long your system has been running for (and, as you will soon see, how long ago the logs were rotated), this log file may be very long, with many various kinds of events recorded. Obviously not all of these logs describe security events; however, these logs can be very useful when troubleshooting many kinds of system behaviour, including in the case of investigating a security breach.

Using your own judgement, attempt to find security relevant details within your messages log file.

As an example, my own /var/log/messages file contains the lines:

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Setting up rules from /etc/sysconfig/SuSEfirewall2 ...

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet1

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet8

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Firewall rules successfully set

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Script /etc/ppp/ip-down finished (pid 342), status = 0x0

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Exit.

This activity was triggered when I disabled the VPN I was using, which triggered a reload of the firewall rules. On an openSUSE system, configuration for the firewall is stored in /etc/sysconfig/SuSEfirewall2.

As is typical, each Syslog entry starts with a timestamp: for example, “Jan 21 17:16:26”. This is followed by the name of the computer, in my case “linux-leedsbeckett”. The next part is the name of the service that sent the log event. In the above example this includes logs sent by “SuSEfirewall2”, and “pppd”. In the case of pppd, a process id (pid) is also included. Following this is the actual log event (message) that was sent to Syslog.

Watching for file changes

Since keeping an eye on log files is a common security and sys-admin task, it is worth exploring a few methods.

Tail is a command that prints the last few lines of a text file:

sudo tail /var/log/messages

A simple method of keeping an eye on a file is to follow the end of a text file.

Run:

sudo tail -f /var/log/messages

This will block waiting for input, and when new lines are added, they will be displayed.

Similarly, the less program can “follow” the end of a file:

Run:

sudo less /var/log/messages

Then press Shift+F.

(Press Ctrl-C, Q to exit when you are done.)

Another useful technique is to watch for changes in the output of a command using “watch”. Run:

watch -d ls -la /var/log/messages

(Press Ctrl-C to exit when you are done.)

This will continuously display the output of the ls command, and highlight any changes, such as, for example, if the file size changes because new entries are logged.

Note that openSUSE is typically configured to also log kernel log events to virtual terminal 10. View the virtual terminal:

In oVirt: choose Send Key from the main console window menu and select Ctrl+Alt+F10 and to return to the desktop environment press Ctrl-Alt-F7.

In VMware: Press Ctrl-Alt-F10 to view the log via the terminal, and to return to the desktop environment press Ctrl-Alt-F7.

Writing to Syslog from the commandline

It is important to realise that most local programs (that is, programs running on your computer) can send messages to the Syslog daemon to log.

From the shell prompt run:

logger Hello, world!

Now, have another look at the end of your messages file. You will find your message, as reported by your username.

Any program can decide how to name its Syslog entries.

logger -t some-program Hello, World!

(where some-program is replaced something including your name: for example, “logger -t cliffes-program Hello, World!”)

As this implies, you can not necessarily trust all log entries, since an attacker on your system could craft their own log entries, to make them look like they are coming from other programs on your system.

Understanding Syslog

Not all Syslog messages end up in /var/log/messages.

Run:

logger -t NetworkManager Network doing something interesting!

On an openSUSE system, this message will not typically end up in /var/log/messages, since NetworkManager has its own log file at /var/log/NetworkManager.

You will find your new message here:

sudo tail /var/log/NetworkManager

Also, emergencies and warnings are treated differently.

Each Syslog event has a priority, which is made up of a facility (auth, user, etc), and a level (alert, crit, etc). See “man logger” for a list of facilities and levels.

Run this to generate an emergency event:

logger -p user.emerg Oh no!

This message will typically be sent to every terminal, and will generally even generate a popup notification.

While this kind of event will also be logged to /var/log/warn:

logger -p user.warn Warning: something is not right...

Writing Syslog configuration rules 

The behaviour is configured in /etc/rsyslog.conf (or /etc/syslog, depending on the version of Syslog you are using).

Open the Syslog configuration file for editing:

sudo vi /etc/rsyslog.conf

(Remember: editing using vi involves pressing “i” to insert/edit text, Esc, then “:wq” to write changes and quit.)

Read through the configuration file, to understand how the behaviour is configured. Try to understand how the logs are sent to virtual terminal 10 (as you previously accessed via Ctrl-Alt-F10).

Add a rule that sends all messages from the program “mymonitor” to /var/log/mymonitor, by adding these lines:

if ($programname == 'mymonitor') \
then    /var/log/mymonitor

Restart Syslog so that it re-reads its configuration:

sudo systemctl restart rsyslog

Write to Syslog to test your new rule:

logger -t mymonitor Hello, World!

And check that it has written to your new config file:

sudo tail /var/log/mymonitor

Now, use what you have learned to add a rule so that any sudo command generates a message to all users (which would typically be sent on terminals and as a popup notification).

Hint: look at how the existing emergency messages rule works, and combine that method of output with the rule above, modified to be triggered by sudo. Remember to reload Syslog.

Remove the rule you added above, before continuing.

Network logging

Note that it is not uncommon for a Syslog log file (such as /var/log/messages) to contain entries originating from other systems on the network. There are many benefits of logging to a central server: if an attacker compromises one of the systems (so long as the computer that has been broken into is not the log server!), they cannot delete or alter existing logs; also, it simplifies log management and monitoring if the various logs can be accessed from a central location. Of course, consequently the security of the log server becomes increasingly important.

You will now configure your local host OS to accept Syslog events from other computers.


Help: you can complete this task by working with a classmate or by logging into two openSUSE VMs.  If you need a second openSUSE VM, clone it now before you make any further changes to the one you have been working on.  If you do not clone your current VM and use another, you will have to install and start the rsyslog service on that VM.  To clone the VM:

Right-click on the VM in the list in oVirt Manager and select “Clone VM” from the list.

The cloning process will take a little time.  You can click the disk tab towards the bottom of the browser to monitor the progress.


On your openSUSE VM, Syslog network logging is configured in /etc/rsyslog.d/remote.conf. If you are using another version of Linux, the rules discussed in this section can be added to the Syslog config files, such as /etc/syslog.conf.

On your openSUSE VM  (the soon-to-be log server), edit the configuration file:

sudo vi /etc/rsyslog.d/remote.conf

(Remember: editing using vi involves pressing “i” to insert/edit text)

Traditionally, Syslog uses UDP, but we will use TCP (as has become common), since it is more reliable. Uncomment (remove the #) from these two lines:

$ModLoad imtcp.so

$InputTCPServerRun <port>

(Many Unix config files use ‘#’ to denote that a line is a comment that is not to be processed, so by removing those from the beginning of the line you are putting them into effect.)

And change the <port> to 10514.

Save your changes, and exit vi (press Esc, then “:wq” to write and quit).

Restart Syslog, for your changes to take effect:

sudo service rsyslog restart

If you like, you can port scan your own machine, to confirm that the port is now open:

nmap localhost -p 10514

Now, note your own IP address of your newly configured Syslog server:

/sbin/ifconfig

Configure this first system’s firewall to accept connections to TCP port 10514:

Hint: on openSUSE (if you are not using openSUSE, you can instead use IPTables), start YaST, then Security and Users > Firewall, Custom Rules > Add

Set the Source Network. For the simplest approach, “0/0” will allow connections from any computer. The security can (and should) be improved by only allowing connections from specific IP addresses or ranges.

Set the Destination Port to “10514”

From a second openSUSE VM. If you like you can get a classmate to complete this from their system:

If the two computers you are using have the same hostname (as will happen if you are both using openSUSE VMs), the resulting logs will be hard to make sense of. (To find out the local hostname, run “hostname”.)

If you are using the openSUSE VM  for both computers, change the hostname of this computer, so that it is different to the first computer:

sudo vi /etc/HOSTNAME

Edit “linux-djla.suse” to something else (no spaces).

Restart the second computer.

Check that the second computer can see the newly opened Syslog TCP port. Run:

nmap -Pn -p 10514 IP-address-of-new-syslog-server

(Where IP-address-of-new-syslog-server is as noted earlier.)

You should see the port state as “open”. If not, check the server’s firewall rules, and recheck that the service is running.

Configure the second “remote” computer to send Syslog messages to the IP address of the new Syslog server...

sudo vi /etc/rsyslog.d/remote.conf

Uncomment (remove the #) from this line:

*.* @@remote-host

(Hint: note the two ‘@’ symbols which denotes TCP, not one, which would indicate UDP)#i#

And change remote-host to IP:10514, where IP is the previously noted IP address of the server. For example, “*.* @@192.168.201.144:10514”.

Still on the second system, restart Syslog, for your changes to take effect:

sudo systemctl restart rsyslog

From that second system, all Syslog messages will now be automatically forwarded to the remote server. Run:

logger “my-name’s remote system

(replace my-name with your actual name)

Confirm that that message was logged to the first computer, and that the other computer’s name is shown in the logs.

sudo tail /var/log/messages

One of the benefits of logging to a remote system is that you have a backup of your logs, since they will be recorded on both machines. It is also wise to maintain a separate backup, incase both systems are compromised. Also, note that a spool can be configured, so that if there are network problems a system sending log messages will re-attempt to send them.

Logrotate

A busy server may have a very large number of log entries. For this reason Unix has a “logrotate” tool, which moves old log events into a separate file, and compresses them so that they take up less space.

Logrotate typically runs daily, and as such a script for running logrotate may be present in:

ls /etc/cron.daily/

(Note the presence of a logrotate script.)

Open /etc/logrotate.conf:

sudo less /etc/logrotate.conf

As you can see, this file refers to the /etc/logrotate.d directory, which contains rules for managing logs. Press “Q” to quit less.

Look at the logrotate configuration for syslog:

less /etc/logrotate.d/syslog

Check whether there are any compressed messages files on your system:

ls /var/log/messages*

If you only see the file “/var/log/messages”, then force logrotate to happen now:

sudo /usr/sbin/logrotate -f /etc/logrotate.d/syslog

Now try “ls /var/log/messages*” again

Depending on how long your system has been running, you will probably notice the presence of many compressed log files over time.

Figure out how to decompress one of the previous log files, and inspect its contents.

Command history

Related to log management, is command history; which can be a useful source for identifying what happened during/after a security incident.

Bash (the most popular Unix interactive shell), stores a history of commands run.

Run:

history

(for details: “man history”)

This file is written to each time a Bash shell terminates.

As you can see, a detailed record is kept. However, it is trivial to modify:

vi ~/.bash_history

If you start a new Bash instance your modified history will be loaded:

bash

history

Clear your history with:

rm ~/.bash_history

(this deletes the file)

history -c

(this clears the list from memory, so when you exit, the blank history is written)

Regular expressions

As you have seen, log files can be large and detailed. Looking for the details you are interested in can be tedious. However, use of regular expressions (AKA regexp or regex) can be very helpful, and make this much easier – they can help you to cut through the noise.

A regex is a pattern describing some text. A regex can be used to filter for matching text, or capture parts of matching text. There are lots of tools that accept regex patterns, such as the Unix commands grep, awk, sed, less, and vi. Regex are a powerful way of processing text, and as such regex are available in most programming languages, to make processing text much easier[1].

For the sake of explanation, the following examples will show how regex can be used to search log files.

As mentioned earlier, my messages log file includes:

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Setting up rules from /etc/sysconfig/SuSEfirewall2 ...

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet1

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet8

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Firewall rules successfully set

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Script /etc/ppp/ip-down finished (pid 342), status = 0x0

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Exit.

The simplest form of regex can search for standard characters, so the following regexp:

leedsbeckett

would find matches in all of those lines. We can see this in action by using the command grep, which is a standard Unix command that searches through files for lines containing matches to a regex. The “--color” argument asks grep to highlight in colour the part of the lines that match. So on my computer I can search for the text “leedsbeckett”, and the output would include those lines described previously:

sudo grep --color 'leedsbeckett' /var/log/messages

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Setting up rules from /etc/sysconfig/SuSEfirewall2 ...

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet1

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: using default zone 'ext' for interface vmnet8

Jan 21 16:52:22 linux-leedsbeckett SuSEfirewall2: Firewall rules successfully set

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Script /etc/ppp/ip-down finished (pid 342), status = 0x0

Jan 21 17:16:26 linux-leedsbeckett pppd[32076]: Exit.

Try searching through your own log file, for matches to a specific query. Run:

sudo grep --color ‘kernel’ /var/log/messages

The above should output all of the log entries that were sent by the kernel.

If we want to find something more complicated, we can use regex special characters to create patterns that match multiple texts. Run:

sudo grep --color 'sudo:\|su:' /var/log/messages

Tip: if at this point you see a long list of messages sent to the screen, you likely forgot to remove the Syslog rule you created earlier.

Tip: Some versions of grep do not enable regex by default so you either need to use the -E flag or use egrep instead.

This will show all of the log entries created by a user attempting a su or sudo. This would be a security sensitive action that would be worth checking for.

This is achieved by the use of the “|” (pipe) character, which describes alternative patterns. Note that (somewhat confusingly) grep required a “\” (which is the escape character) before the special character. Unfortunately, this is not the case with most regex tools, usually it is the other way around, where special characters always have their special meaning unless they are escaped.

Another way of searching for the same thing would be:

sudo grep --color 'su\(do\)*:' /var/log/messages

This works by grouping with “( )” (parentheses); the “*” character states that the proceeding group must appear zero-or-more times. So “su” or “sudo” both match the above regex.

These special characters are used to state how many times the proceeding “atom” (section) occurs:

Some other special characters:

Note that there are a few subtle varieties of regex (as we have seen, grep requires escape slashes before certain special characters), but for the most part the above rules apply.

So for example, run:

sudo grep --color 'su\(do\)*:.*USER=root.*grep' /var/log/messages

Figure out what the above is matching, and make sure you understand how every section of the above regex works.

You can also do all kinds of neat tricks such as matching repeating text (using backreferences), and changing how “greedy” your matches are.

There are plenty of good tutorials available online. You can learn more about regex matching from sources such as:

man grep

http://gnosis.cx/publish/programming/regular_expressions.html

Using what you have learned, write a grep command that performs a regex on /var/log/messages for log entries sent by the kernel.

Once that is working, extend your regex to only match log events sent in the afternoon (12:00) today (hint: consider the date).

Windows and Logs

Although Windows does not natively support Syslog (it uses what is known as “Event Logs”, which can be accessed via the Event Viewer), it is possible to install software that makes this possible, allowing all of your logs to be centralised with Unix logs.

This resource provides some more information:

http://www.syslog.org/logged/windows-syslog/

Note the additional challenge below, relating to Windows log management.

Unguided Problem-based tasks

The journal entries created by journald are considered to be more secure than the log entries created by the older syslog system.  This is due to the fact that some of the contents of the message fields are taken directly from the system and the user/programmer cannot alter these unless the journald service itself has been compromised.

In a table, list 5 common user defined journal fields and 5 trusted journal fields along with a description of each.


Complete the blank table provided in the submission sheet for this lab. Label it “Logs-A1”.


Use logger to send a log message that would fool a sysadmin into thinking a sudo command was successful.


Take screenshots of the logger command and the tail of /var/log/messages, as evidence that you have completed this part of the task.

Label it as “Logs-A2”.


On Windows, open Event Viewer, view the logs, and browse through the Security logs. Use the command line tool “eventcreate” to add a log event. Browse to the event you have created.


Take a screenshot your added log event in Windows, as evidence that you have completed this part of the task.

Label it as “Logs-A3”.


Use two or more Windows systems, and configure remote logging, where all logs are forwarded to a central log server.


Take screenshots of configuration changes and use, as evidence that you have completed this part of the task.

Label them as “Logs-A4”.


Download and install a log monitoring tool of your choice, and determine how to monitor sudo commands.


Take screenshots of configuration changes and use, as evidence that you have completed this part of the task.

Label them as “Logs-A5”.


Extend your regex from the Regular Expressions Section above, to only match log events sent by the kernel in the afternoon today or yesterday.


Take a screenshot showing a grep command with it successfully returning log entries sent by the kernel, in the afternoon today or yesterday.

Label them as “Logs-A5”.



[1] Programming languages such as Perl have regex as a core component of the language, while others such as C, Java, C#, and C++ have libraries that can provide regex processing.