Add timestamp to SSH verbose logs [STDOUT & Log File]

Why to add timestamp to SSH VERBOSE logs?

Normally if you are using SSH client without any additional options then you will not get any output on the console other than password prompt or Host Key Checking message. But then sometimes to debug SSH related issue we enable verbosity while initiating the SSH connection using -v. We can also increase the count of -v to add more level of verbosity such as -vvv.

Normally this should be enough for most scenarios but at times we would like to store the verbose logs into any log file. We may also need to have timestamp for the verbose logs to debug the issue based on the timestamp from SSHD server.

In this tutorial I will share the steps to:

• Store the STDOUT and STDERR logs from SSH client into a log file
• Add timestamp to SSH VERBOSE logs inside the log file

1. Make sure SSHD server is up and running

Since we are dealing with SSH client, so obviously we need one SSHD server up and running. I will not be able to share the steps to configure SSHD server as that is not in the scope of this article:

systemctl status sshd

Sample Output:

2. Initiate SSH connection with VERBOSE

Now we will just try to initiate a SSH connection our SSH server i.e. 192.168.0.151. By default as expected we are getting the logs on STDOUT and no timestamps:

ssh -v 192.168.0.151

Sample Output:

3. Add timestamp to SSH Client VERBOSE logs

Next we will add timestamp to SSH Client logs and print the VERBOSE logs on the console. We will achieve this by using a pipe to process the SSH output and pass it to while loop. The while loop will process individual line and add timestamp to each line as a prefix before printing it on the console.

For, example here we have added while loop to our SSH command:

[root@controller ~]#  ssh -v 192.168.0.151 exit 2>&1 | while read line; do printf '[%s] %s\n' "$(date '+%Y-%m-%d %H:%M:%S')" "$line"; done
[2021-09-16 11:31:54] OpenSSH_8.0p1, OpenSSL 1.1.1c FIPS  28 May 2019
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/ssh/ssh_config
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/ssh/ssh_config.d/05-redhat.conf
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config
[2021-09-16 11:31:54] debug1: configuration requests final Match pass
[2021-09-16 11:31:54] debug1: re-parsing configuration
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/ssh/ssh_config
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/ssh/ssh_config.d/05-redhat.conf
[2021-09-16 11:31:54] debug1: Reading configuration data /etc/crypto-policies/back-ends/openssh.config
[2021-09-16 11:31:54] debug1: Connecting to 192.168.0.151 [192.168.0.151] port 22.
[2021-09-16 11:31:54] debug1: Connection established.
[2021-09-16 11:31:54] debug1: identity file /root/.ssh/id_rsa type 0
[2021-09-16 11:31:54] debug1: identity file /root/.ssh/id_rsa-cert type -1
[2021-09-16 11:31:54] debug1: identity file /root/.ssh/id_dsa type -1

As you can see, now our SSH client logs have a timestamp for each line.

4. Store SSH client VERBOSE logs into log file

Next we will store these DEBUG VERBOSE logs into a log file instead of printing everything on the console. We will append all the SSH log output from while loop and store those lines into a separate log file as shown below:

[root@controller ~]#   ssh -v 192.168.0.151 exit 2>&1 | while read line; do printf '[%s] %s\n' "$(date '+%Y-%m-%d %H:%M:%S')" "$line"; done > "/tmp/ssh-debug.log"
root@192.168.0.151's password:
[root@controller ~]#

As you can see, this time we didn't get any output on the console.

5. Verify SSH VERBOSE logs are stored with timestamp

Next check the log file where we stored the SSH verbose logs i.e. /tmp/ssh-debug.log

 ~]# head /tmp/ssh-debug.log

Sample Output:

As expected, our logs from SSH client are properly captured inside log file along with timestamp.

What's Next

You can also add timestamp to SSHD debug logs on the server side. Read more at Add timestamp to SSHD DEBUG logs

Summary

In this tutorial I shared the steps to add timestamp to SSH VERBOSE logs and store the logs into a different log file. This is useful when we have to debug any SSH related issue where you can compare the debug timestamp from server and client and try to identify the root cause.

Now either you can print SSH logs on console or store them into a log file based on your requirement. Let me know if you have any questions or feedbacks using the comment section.

References

man page for SSH