Introduction

In this article, we will see how to analyze SSHD (SSH server-side) logs with basic command-line tools “grep, cat, wc, head, tail, awk” to potentially find any suspicious requests on our SSH server.

By default, we have the SSHD logs in /var/log/auth.log . This file contains not only SSHD logs but also CRON, SUDO and PAM logs.

Basic Log stats

First, we can perform basic stats on our log file:

  • Number of log entries
  • First and last entry
  • CRON, SSHD, SUDO entries

Number of log entries

We started with basic print number of lines in the log file with the “wc” command.

$ cat auth.log | wc -l
276

On my home server, there is only 276 log entries but on a server accessible from the Internet, there will be much more amount of data, especially if the ssh port is open due to bots or malicious actors.

We can get more informations like the first entry and the last entry on the log file to get the timeline information (beggining, ending).

$ cat auth.log | awk 'NR==1; END{print}'
Mar 27 00:09:01 x230 CRON[756922]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)  #First line
Mar 28 13:17:01 x230 CRON[2692534]: pam_unix(cron:session): session closed for user root	#Last line

As said in the introduction, the log file does not only contain information from SSHD but also from CRON, SUDO command and PAM, so we can also classify the data by type of service with the “grep” command.

$ cat auth.log | grep "sshd" | wc -l
7

Here we get number of entries for SSHD service on the auth.log file.

Services Logs

For the SSHD logs, we simply add a pipe and a grep command with the “sshd” flag. We can also perform this search with CRON and SUDO for finding which entries interest us more.

$ cat auth.log | grep "sshd" 
Mar 28 11:27:03 x230 sshd[2168909]: Accepted password for docker from 192.168.1.31 port 36254 ssh2
Mar 28 11:27:03 x230 sshd[2168909]: pam_unix(sshd:session): session opened for user docker(uid=1000) by (uid=0)
...

We can also print the first and last entry:

$ cat auth.log | grep "sshd" | awk 'NR==1; END{print}'
Mar 28 11:27:03 x230 sshd[2168909]: Accepted password for docker from 192.168.1.31 port 36254 ssh2
Mar 28 13:31:12 x230 sshd[2758419]: PAM 1 more authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.31  user=docker

As said before, the auth.log file contains “sudo” logs for users using the sudo command. This can be interesting if you are looking to see if a user is trying to execute commands as root with or without permissions.

$ cat auth.log | grep "sudo"
Mar 28 11:27:21 x230 sudo:   docker : user NOT in sudoers ; TTY=pts/3 ; PWD=/var/log ; USER=root ; COMMAND=/usr/bin/cat auth.log

Or the CRON tasks (a UNIX utility which performs commands a scheduled intervals).

$ cat auth.log | grep "cron"
Mar 27 00:09:01 x230 CRON[756922]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Mar 27 00:09:01 x230 CRON[756922]: pam_unix(cron:session): session closed for user root
Mar 27 00:17:01 x230 CRON[794889]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Mar 27 00:17:02 x230 CRON[794889]: pam_unix(cron:session): session closed for user root
Mar 27 00:39:01 x230 CRON[899453]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Mar 27 00:39:01 x230 CRON[899453]: pam_unix(cron:session): session closed for user root
...

SSHD Logs Parse

Now we move on to the section that interests us the most : Parse and analyze SSHD logs to find users login attempts and malicious requests on the SSH protocol like port scanners.

Logins

On logs file with thousands of entries, it’s complicated to find malicious traffic. But with a parsing technique we can extract the data we are most interested in.

First, we can print the successful logins with this command:

$ cat auth.log | grep sshd | grep 'session opened'
Mar 28 11:27:03 x230 sshd[2168909]: pam_unix(sshd:session): session opened for user docker(uid=1000) by (uid=0)

The server only had one successful logins over 24 days. They are all from me as I did not create any other users for the system.

We can also print the number of different IP addresses which had successful logins:

$ cat auth.log | grep -oE '.*Accepted publickey.*' | awk '{ print $11 }' | sort | uniq

On the otherside, we can retrieve failed logins attempts for invalid users (local user not existing).

$ cat auth.log | grep 'Invalid user' | wc -l

We can also get the number of invalid usernames used in logins attempts:

$ cat auth.log | grep -oE 'Invalid user.*' | awk '{ print $3 }' | sort | uniq | wc -l

But also existing user with a bad password (maybe a mistake or brute-force if many attempts)

$ cat auth.log | grep sshd | grep 'Failed password'
Mar 28 13:30:55 x230 sshd[2758419]: Failed password for docker from 192.168.1.31 port 36256 ssh2
Mar 28 13:30:59 x230 sshd[2758419]: Failed password for docker from 192.168.1.31 port 36256 ssh2

Port Scanners

Port scanners usually connect to a port and immediately disconnect. This connection type is recorded in the log as “Received disconnect”. So we put this record in the grep command.

$ cat auth.log | grep -oE 'Received disconnect.*' | wc -l

This command return the number of port scanning attempts detected.

If your server is expose on the Internet, you can print the public IP addresses that did port scanning:

$ cat auth.log | grep -oE 'Received disconnect.*' | awk '{ print $4 }' | sort | uniq | wc -l

Conclusion

We have seen the basics of SSHD log parse, an analyze can be easily complete manually with the commands below, in case investigation or simply find if your server receive unintended connections. For those who wonder what countermeasures we can add to counter bruteforce attacks (ports and login/password), I invite you to check fail2ban, a very powerful and free tool very well known and used in companies.

You can now practice with this good challenge on the BTLO platform: https://blueteamlabs.online/home/challenge/17 (active challenge, don’t post any write-ups)

Sources: