Logging with shell script - catch STDERR to log with timestamp

Question

SOLVED:

A few months ago, I gain interest in logging in shell scripts.

The first idea was a manual logging function such as this one:

add2log() {
    printf "$(date)\tINFO\t%s\t%s\n" "$1" "$2" >>"$logPATH"
}

But I wanted to automatise it, such as that STDERR would be automatically logged.

It's been some time now that I've found a satisfying answer, and I'm finally taking the time to share it.

---

For each of my shell script, I now use a "main.sh" that holds the log functions as well as the config (setting up log and config files). Here's what it looks like:

#!/bin/bash

###################################################################
# MY HEADERS
###################################################################


#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
#~~~~~~~~~~~~~~~~~~Global vars

mainScriptNAME=$(basename "$0")
mainScriptNAME="${mainScriptNAME%.*}"
mainScriptDIR=$(dirname "$0")
version="v0.0"
scriptsDIR="$mainScriptDIR/SCRIPTS"
addonsDIR="$mainScriptDIR/ADDONS"


#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
#~~~~~~~~~~~~~~~~~~LOGGER FUNCS

manualLogger() {

    # $1=PRIORITY $2=FUNCNAME $3=message
    printf "$(date)\t%s\t%s()\t%s\n" "$1" "$2" "$3" >>"$logFilePATH"
}

stdoutLogger() {

    # $1=message
    printf "$(date)\tSTDOUT\t%s\n" "$1" >>"$logFilePATH"
}

stderrLogger() {

    # $1=message
    printf "$(date)\tSTDERR\t%s\n" "$1" >>"$logFilePATH"
}


#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
#~~~~~~~~~~~~~~~~~~LOG & CONF

createLog() {
    # code to set and touch logFilePATH & confFilePATH
    manualLogger "INFO" "${FUNCNAME[0]}" "Log file created."
}


#~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
#~~~~~~~~~~~~~~~~~~MAIN

#
createLog

#run scripts
{

    #
    source "$scriptsDIR/file1.sh"
    doSomthing1
    doSomthing2

    #
    source "$scriptsDIR/file2.sh"
    anotherFunction1
    anotherFunction2

    ...


} 2> >(while read -r line; do stderrLogger "$line"; done) \
1> >(while read -r line; do stdoutLogger "$line"; done) 

In other words:

• all scripts/functions I want to run are in separate files in a ./SCRIPTS folder (so my main.sh is almost always the same)
• I call all these scripts in a group { ... } to catch their STDOUT and STDERR
• their STDOUT and STDERR are redirect to their respective logger functions

The log file looks like this (examples of one manual logger, one STDOUT logger, one STDERR logger):

Lun 23 mai 2022 12:20:42 CEST   INFO    createLog() Log file created.
Lun 23 mai 2022 12:20:42 CEST   STDOUT  Some standard output
Lun 23 mai 2022 12:20:42 CEST   STDERR  ls: sadsdasd: No such file or directory

The group makes it that ALL output is gathered in log. Instead, you obviously could use the redirect 2> >(while read ... and 1> >(while read ... as you wish for each function. Such as doSomthing1 as its STDOUT and STDERR going to log, but doSomthing2 only has its STDERR redirect.

Answer 1

By the looks of it, it seems that you simply are adding debug statements. What do you mean by "heavy" here? In a Bash script (or rather any programming language for that matter), if you need to echo something, you need to have a statement which tells the interpreter to echo the contents you have passed.

There is no substitute for writing the command if you want an action to take place at a certain point in your script (or any piece of code).

You can have all sorts of tricks using IO redirection, but you have to have two statements - one at the start and one at the end to achieve what you want.

If you want a thorough logging of your script, refer to set -x. If you want to log only some functions of your script, use set -x with those functions in suhshells.

(set -x; func1)

Answer 2

I use flag files in a dedicated directory:

foo.bash:
  
#!/bin/bash
[[ -f $HOME/.local/debug/foo.debug ]] && \
  source $HOME/.local/debug/foo.debug
...

I can put anything I like in the foo.debug file, including stuff like debug_foofunction=1, and later, in foo's foofunction I can use debug_foofunction (carefully - it might be undefined) to invoke (or not) debug code.
If I simply rm $HOME/.local/debug/foo.debug, all debugging code is turned OFF. If I change it to debug_foofunction=0 I can turn OFF foofunction debugging, while leaving other debugging settings (e.g. debug_foootherfunction=1).

Read man bash, about the "trap" builtin.

The real solution is to not write complicated scripts. Use a programming language that maps onto your problem set.

Always paste your script into https://shellcheck.net, a syntax checker, or install shellcheck locally. Make using shellcheck part of your development process.