How to tail a log with live server clock

At work I have to watch my server’s error log. Good old tail -F /path/to/log runs over SSH all day, every day. Each entry is timestamped. Sometimes those timestamps give me trouble. The age of a timestamp is found by subtracting it from the current time. If I need to know whether the last error occurred 1 minute ago or 61 minutes ago I have to contend with:

  • timestamps in UTC vs. local clock in CST
  • timestamps in 24h vs. local clock in 12h
  • terminal window on second screen vs. clock on main screen
  • daylight savings vs. non-crazy time
  • being at home vs. traveling in other time zones

Finding the age of a timestamp should be simpler than that! So I put a real-time UTC clock in the most convenient place I could find: on the blank line where the next log entry will be written. It refreshes itself every second. Log entries overwrite it and then it reappears again on the new blank line.

The clock on the next line refreshes itself.

The clock on the next line refreshes itself.

Now I can find the age of the last entry without thinking about time zones or daylight savings, without turning my head to check the clock, and without even holding any numbers in my head. Eyeball math. Success!

#!/bin/bash
ssh $1 $(cat <<COMMAND
    while true; do
        echo -ne \`date +"[%d-%b-%Y %H:%M:%S UTC]"\` "\r";
        sleep 1;
    done &
    tail -Fn`tput lines` $2
COMMAND)
echo

If you save this script as st in your path and chmod +x it you can invoke it with st example.com /var/log/file (provided you can ssh example.com and read the file).

I used a few small tricks to compose this solution.

  • the while loop runs in the background (done &)
  • echo -n prints its arguments without a line feed
  • echo -e interprets escape sequences, converting "\r" into a carriage return
  • bonus: `tput lines` passes the local terminal height to tail
  • the final echo gives your prompt a fresh line when you exit with ^C

After SSH connects, the loop starts sending [timestamp]\r to the terminal every second. The carriage return moves the insertion point back to the start of the line without moving it down to the next line. That explains the location of the highlighted character in the image above.

Then tail fills your terminal window with log entries and continues printing new entries as they appear, overwriting the clock. No space wasted, no information lost.

Caveats:

  • log entries must be timestamped and must end in a newline
  • date format is up to you
  • n`tput lines` is optional
  • the clock might draw over log data

That last point is theoretical. It hasn’t been an issue in the two months since I started using this. I also tried to force the clock to overwrite the tail output under abnormal conditions. The only way I could do it was by manually appending to the file without a trailing newline. I guess it depends on the size of the log entries and how they are written. Either way, it’s only terminal output. The log file itself is unmodified.

The script I posted above isn’t exactly what I have been using. It was modified for clarity and generality. I added positional parameters and $(cat <<heredoc) to get clean newlines without having to escape too much. Since I only use this utility to tail one file on one host, the original looks more like this one-liner:

ssh example.com 'while true; do echo -ne `date +"[%d-%b-%Y %H:%M:%S UTC]"`"\r"; sleep 1; done & tail -Fn'`tput lines`' /var/log/file'; echo

1 Comment

  1. Reblogged this on kwight.ca and commented:

    Super helpful timestamp clock while tailing error logs.

Follow

Get every new post delivered to your Inbox.

Join 1,667 other followers

%d bloggers like this: