The Problem

As a lazybusy system administrator I am swamped with email from my cron jobs. My first approach was simply to relegate the e-mail from cron jobs to a separate mail folder. This solved my immediate problem with a bloated inbox, but obviously all I had done was move my problem to another folder; still, at least all the e-mail was in one place. A second solution was to add redirection lines to all the entries in crontab. Here I had another choice: do I append to the log files or do I clobber them? Appending seemed the way to go and with modern discs there was little chance I would run out of disc space. Problem solved!

Of course, out of sight is out of mind and it wasn’t long before I was not bothering to scan the log files and of course a small problem was overlooked and very soon became a large — almost catastrophic — problem. Back to my original question: How do I limit output from my shell scripts, but still generate enough context so I know what is happening when things went wrong?

A Solution

Some Background

The ideal solution for my problem is that a successful shell script invocation would generate no output at all. Only when there are warning or error messages will there be output produced. This means that the only e-mail I get is from cron jobs that require my attention.

My shell scripts tend to fit into the following pattern:

1. Output a banner
2. While work to be done
1. Output a section header
2. Do some work, outputting messages if necessary
3. Output a footer

First Steps

It is obvious that I only need to do (1) (2.A) and (3) if (2.B) generates output. Some thought is required. The first step is to produce a simple function to datestamp the output. This is a feature of almost all of my scripts:

log() { echo "$(date) $1"; }

A first attempt had each of the calls to “log()” protected with code like:

if [[ -z $head ]]; then
    [[ $bann ]] || {log "The banner"; bann="Done"; }
    log "Section heading"
    head="Done"
fi
log "The status message"

There are many problems with this approach, not the least of which is that the banner and heading code soon overwhelms the lines that are actually doing the work. A better approach is required.

First Refinements

The next step is to combine the “$head” and “$bann” flags with their respective text headings this produces slightly simplified code:

bann="The banner"
head="Section heading"
if [[ $head ]]; then
    [[ $bann ]] && { log "$bann"; bann=""; }
    log "$head"
    head=
fi
log "The status message"

This is better, but with “$head” and “$bann” doing double duty there appears to be no reason now, why the section header and banner code could not be part of the “log()” function. Something like this:

logd() { echo "$(date) $1"; }
banner() { [[ $bann ]] && { logd "$bann"; $bann=""; } }
header() { banner; [[ $head ]] && { logd "$head"; $head=""; } }
log() { header; logd "$1"; }

To use these functions the script must initialise “$head” and “$bann” as required. Eg.

bann="The banner"
#
# Do stuff
#
head="Section heading"
#
# Do more stuff
#
log "The status message"

The 'Footer' Problem

There are still some minor æsthetic problems, in that the banner and header will have the same datestamp as the log line that caused them to be displayed, but the main problem is that it is difficult to determine if any output has been generated at any particular point in the shell script. It would be a pity if the only output from the shell script was generated by the final message to say that the script was completed.

A straightforward change to “logd()” would suffice:

logd() { flag="yes"; echo "$(date) $1"; }

And a new function to handle output of the footer:

footer() { [[ $flag ]] && logd "${1:-Done}"; }

This solves the problem, at the expense of continually updating the “$flag” variable. A change to the definition of “logd()” to incorporate a collapsing function deals with this continual, unnecessary update:

logd() {
    flag="yes"
    logd() { echo "$(date) $1"; }
    echo "$(date) $1"
}

This works by setting the “$flag” variable and then redefining “logd()” to exclude the assignment to “$flag”, finally the output is performed. Subsequent calls to “logd()” will avoid the overhead of the unnecessary assignment.

Bringing all the definitions together gives us the following:

logd() {
    flag="yes"
    logd() { echo "$(date) $1"; }
    echo "$(date) $1"
}
banner() { [[ $bann ]] && { logd "$bann"; $bann=""; } }
header() { banner; [[ $head ]] && { logd "$head"; $head=""; } }
footer() { [[ $flag ]] && logd "${1:-Done}"; }
log() { header; logd "$1"; }

To use them initialise, “$bann” with some text describing the function of the script. At each significant point in the script, assign “$head” with the section name. Finally make calls to the “log()” function whenever an error or warning message is desired.

My cron jobs do not need their output redirecting and I only get mail from cron jobs that have something important to bring to my attention. Bliss.

The Final Curtain

The code as described above is a cut-down version of my original code; simplified to illustrate my points. The final version is included below and can be retrieved from here. This version deals with the banner and header datestamp problem and also adds the facility to remove recurring items from the resultant message text (e.g. common parts of path names).

#!/bin/bash
#
#   File:   log.sh
#   Author: Roy Trubshaw
#
#   Routines to display, possibly datestamped, information to stdout
#
#   Public:
#   setDate     - Enable datestamping
#   setNoDate   - Disable datestamping
#   setEdit edit[='']
#               - Set a path to be edited out of output lines
#   setBanner bann[='']
#               - Set once-only banner text
#   setHeader head[='']
#               - Set periodic header text
#   log text[='']
#               - Output datestamped text with edit text, if specified, removed
#                 from it preceded by a banner line and a header line if
#                 required.
#   elog text[='']
#               - Output datestamped text with edit text, if specified, removed
#                 from it preceded by a banner line and a header line if
#                 required. Then call efooter to exit.
#   footer text[='Done']
#               - Output a final line (only if text has been output)
#   efooter text[='Done']
#               - Output a final line (only if text has been output) and exit
#
#   Private:
#   $d__        - Flag to indicate if datestamp is required
#   $e__        - Text to be removed from output text before output
#   $bd__       - Datestamp for banner
#   $b__        - Text for banner (set to '' once banner has been output)
#   $hd__       - Datestamp for periodic header
#   $h__        - Text for header (set to '' once header has been output)
#   $f__        - Flag to indicate footer required.
#   redefLogd   - Redefines logd to account for all combinations of $d__, $e__ and $f__
#   logd text[=''] date[=now]
#               - Output datestamped text with edit text, if specified, removed
#   banner      - Output banner text if present, set banner text to null
#   header      - Output header text if present, set header text to null
#
d__="#"
e__=
bd__=
b__=
hd__=
h__=
f__=
#
redefLogd() {
    if [[ $e__ ]] ; then
        if [[ $f__ ]] ; then
            if [[ $d__ ]] ; then
                logd() { echo -e "${2:-$(date)} $1" | sed "s,$e__,,g"; }
            else
                logd() { echo -e "$1" | sed "s,$e__,,g"; }
            fi
        else
            if [[ $d__ ]] ; then
                logd() {
                    f__="#"
                    logd() { echo -e "${2:-$(date)} $1" | sed "s,$e__,,g"; }
                    echo -e "${2:-$(date)} $1" | sed "s,$e__,,g"
                }
            else
                logd() {
                    f__="#"
                    logd() { echo -e "$1" | sed "s,$e__,,g"; }
                    echo -e "$1" | sed "s,$e__,,g"
                }
            fi
        fi
    else
        if [[ $f__ ]] ; then
            if [[ $d__ ]] ; then
                logd() { echo -e "${2:-$(date)} $1"; }
            else
                logd() { echo -e "$1"; }
            fi
        else
            if [[ $d__ ]] ; then
                logd() {
                    f__="#"
                    logd() { echo -e "${2:-$(date)} $1"; }
                    echo -e "${2:-$(date)} $1"
                }
            else
                logd() {
                    f__="#"
                    logd() { echo -e "$1"; }
                    echo -e "$1"
                }
            fi
        fi
    fi
}
#
setDate() {
    [[ $d__ ]] && return
    d__="#"
    redefLogd
}
#
setNoDate() {
    [[ $d__ ]] || return
    d__=
    redefLogd
}
#
setEdit() {
    [[ $e__ == $1 ]] && return
    e__="$1"
    redeflogd
}
#
setBanner() { bd__="$(date)"; b__="$1"; }
#
setHeader() { hd__="$(date)"; h__="$1"; }
#
logd() {
    f__="#"
    logd() { echo -e "${2:-$(date)} $1"; }
    echo -e "${2:-$(date)} $1"
}
#
banner()    { [[ $b__ ]] && { logd "$b__" "$bd__"; b__= ; } }
#
header()    { [[ $h__ ]] && { banner; logd "$h__" "$hd__"; h__= ; } }
#
footer()    { [[ $f__ ]] && logd "${1:-Done}"; }
#
efooter()   { footer; exit; }
#
log()       { header; logd "$1"; }
#
elog()      { log "$1"; efooter; }