DX Application Performance Management

Shell scripting: log handler

By Jörg Mertin posted 02-11-2020 11:10 AM

  

Shell scripting: Log handler

when looking out at scripts that are used for practically all projects on the wide internet, especially those hosted in containers, one notices that everyone implements its own way of handling error messages, logging etc.
The main issue with that is that it becomes very difficult to actually deal with the amount of logs being written where and how.

Over time, I have come to my own way of dealing with logs by always importing a small function that deals with the log handling.
What is important in log handling is:

  1. Date - needs to be there to the second
  2. Origin - which app (script) sent it in
  3. Target - where to send the log. Local logfile, or syslog, or even remote syslog?
  4. Show - Show the log messages on the stdout or not?

The major advantage here is that one can define a format the logs need to be displayed, and by just using the same log-function across all scripts, have a normalized logging experience.

Where to use

Imagine a docker environment, and every docker container has its own logging setup. To extract the logs, one has to go to each and every container to extract the logs. And this is where using a log function can come in handy.
Imagine that the docker environment defines a generic log-server (IP Address of a syslog server) and all script that will be executed in the 30 Micro-services log their data onto that syslog server.
Only one place required to look at from now on to get the logs of the executed shell scripts inside of the docker containers.
As a bonus, if the syslog server log format has been configured correctly, that data can also be injected into the AIOPS platform and taken into account on Service alarms etc., and this from one only log-server.

Function: log

When calling this function, all that one needs to do is call it and provide the log message as argument. Date and script will be extracted from the script itself.

###############################################################################
# Log function
#
# Required information/VARIABLES
# VERBOSE: true|false - if set to true, all will be echoed to stdout.
# LOGFILE: Location of Logfile to write data into.
# WRITELOG: true|false - write log message to file?
# SYSLOG: true|false - Send data to Syslog?
# LOGGER: Binary of program sending data to syslog (only required if one wants 
#         to send data to Syslog)
# LOGGEROPT: options to provide to the logger program. If the syslog server is 
#            on a remote server/IP, provide the location here.
# USER: id of user executing the script.
# 
# Call with: log <MESSAGE>
log() {

    # Be verbose
    ! $VERBOSE || echo "> ${PROGNAME}[${PROG_PID}]: $*"

    # no logger found, no syslog capabilities
    if [ $SYSLOG ]
        then
        if [ -x $LOGGER ]
        then
            ! $SYSLOG || $LOGGER $LOGGEROPT -t "${PROGNAME}[${PROG_PID}]:" "$*"
        else
            echo "* FATAL: No $LOGGER logger binary found. Aborting script execution!"
        exit 1
        fi
    fi

    if [ $WRITELOG ]
    then
      if [ -f $LogFile ]
      then
          # Write it all out to a Log-File.
          echo "> $LDATE by $USER ${PROGNAME}: $*" >> $LogFile
      else
      # In case this is the first run, the LogFile will not yet
      # exist. Create it and do the same logic
      touch $LogFile
        if [ -f $LogFile ]
        then
          # Write it all out to a Log-File.
          echo "> $LDATE by $USER ${PROGNAME}: $*" >> $LogFile
        else
          # Final error message - we can't write out logs even
          # though configuration told us to do so. Emergency
          # Exit.
          echo "* FATAL: No existing $LogFile logfile found. Aborting logfile writing!"
          exit 1
        fi
      fi
    fi
} # log function.

Using the "log" function in a shell script

There are multiple ways of using the log function. First, we need it to be available to the actual shell script.
As Copy&Pasting the code from script to script will make it a nightmare to maintain (Imagine you change the function and have 50 scripts it is embedded into).
Best is to have the "common" functions exported into an external file, for example named shmod.inc, and include that function in any script with:

# Source common functions used in scripts
if [ -f /usr/local/shmod/shmod.inc ]
then
    source /usr/local/shmod/shmod.inc
else
    echo "*** FATAL: Missing shared mod !"
    exit 1
fi

If the configuration is correctly set in each script, one can use the log function to log events to a local logfile, to the stdout (console) or to a syslog server (local or remote) as shown next.

Example script on how to use the logger function

The following test-script shows how to use it.

#!/bin/bash
#
# Script Programm Version
VER="Revision: 1.11"

# Path list to search for binaries
PATH=/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/sbin:/usr/local/bin

# Get Program-Name, shortened Version. Removing .sh extension
PROGNAME="`basename $0 .sh`"

# Execution PID.
PROG_PID=$$

# Logger section
# I want it to be verbose.
VERBOSE=true

# Logfiler to use
WRITELOG=true
LogFile=./log/${PROGNAME}.log
# Syslog and options
SYSLOG=true
# As we have a local syslog running, we can use localhost as Target.
# TCP protocol is used, as UDP is a shoot-and-foprget protocol and 
# some log entries can be lost if the syslog server is under high load.
LOGGEROPT="-n localhost -P 514 -T" # 
LOGGER=/usr/bin/logger

USER=`whoami`

# Include file path
INCPATH=./shmod

# Build Date in reverse , for logging function
DATE=`date +"%Y%m%d"`
# Date + Time
LDATE=`date +"%F @ %T"`

# Source common functions used in scripts
if [ -f ${INCPATH}/shmod.inc ]
then
    source ${INCPATH}/shmod.inc
else
    # In case the shared modules file does not exist, this script
    # cannot function.  Emergency Exit with error message.
    echo "*** FATAL: Missing shared mod ${INCPATH}/shmod.inc!"
    exit 0   
fi

#######################################################################
# Actual script - do not modify anything below this poin
#######################################################################

# One way of using the log-message, put it all into the current MSG
# variable and invoque internal funciton "log"
MSG="Starting program"
log $MSG


When executing the sample script, one can see the different log entries it produces:

# Console/stdout
jmertin@calypso:~/work/2020/Blogs/Log$ ./sample.sh
> sample[15026]: Starting program

# Defined logfile
jmertin@calypso:~/work/2020/Blogs/Log$ tail -1 log/sample.log 
> 2020-01-31 @ 12:21:07 by jmertin sample: Starting program

# Syslog
jmertin@calypso:~/work/2020/Blogs/Log$ tail -1 /var/log/syslog
Jan 31 12:21:07 calypso sample[15026]: Starting program

Conclusion

As with every programming language, structured programming can also be reached while writing shell scripts. Remember - a shell-script is just a way to put commands into a file, to be executed in a specific order. However, with time, these "scripts" can become complex and will require some order. And as with every other programming language, one can use functions to actually share code among various scripts and indirectly impose a certain order/format to the execution and output


Next week:Shell scripting: error handler - or how can I catch the error code of executed programs and react upon.


0 comments
17 views

Permalink