logr

Introduction

Logr is a Bash logging utility simplifying debugging and error messages in your Bash scripts. There’s probably a great utility already out there for this, but I didn’t find any that fit my needs.

Logr is basically shorthand for the logger command in Bash. You can use simpler logging commands such as:

logr debug "A quick debug message"
logr notice "One that goes to your log and /var/logs/system.log"

You can source Logr at the beginning of any bash script and enable logging with a simple logr start command. Logr uses logger command to write custom messages to your own log, optionally to STDERR, and notice, warning, and error messages to both of those as well as the system log (/var/logs/system.log), which can be viewed in Console (on Mac).

Logr has no built-in log rotation capabilities, so that needs to be handled via the Apache rotatelogs (/usr/sbin/rotatelogs), newsyslog, or any of the available log management tools.

Because console output from logr goes to STDERR, it can be used in scripts where STDOUT is piped without affecting results.

Configuration

You can change the location of the custom log files with $__logr_LOG_DIR. The default is ~/logs/, but it can be set to anything you want. E.g. in ~/.bash_profile use export __logr_LOG_DIR=${HOME}/custom_path to change it, or define the variables before calling logr start directly in the script.

You can define the name of a custom log when starting logging, or just let it default to ~/logs/scripts.log. You can change the name of the log with $__logr_DEFAULT_LOG. E.g. export __logr_DEFAULT_LOG=my_scripts.

By default, logr uses the “user” logging facility. If you need to change this, you can set $__logr_FACILITY, either in the script itself or in a global init file (i.e. ~/.bashrc or ~/.bash_profile).

Usage

  1. Source the script

     source ~/scripts/logr.bash
    

    You can source the script in a login file (e.g. ~/.bash_profile) and use it in functions added to the main scope by your shell login. Otherwise, source it in a single script and it will stay out of the main scope. Note that sourcing it in a login file does not make it available to scripts run from the shell.

  2. Start the logger
    • A call to logr start begins logging to ~/logs/scripts.log
    • You can override the default log name with logr start LOG_NAME
  3. Call logr in your script where you want log messages

     logr [log|notice|info|debug|warn|error] MESSAGE
    

    If no level is given, it defaults to the “user.info” facility for easy logging

     logr MESSAGE
    

If you set the logging mode to “quiet” (which is default), you can use tail -f to see the results of your script as it runs. Debug and info messages can go to your custom log file without polluting system.log.

Commands

logr start
Must be called first, initializes logging, sets global log file
If the first paramater is “verbose” or “quiet”, it toggles STDERR output (defaults to quiet).
If the first parameter (or second, if called in combination with verbose/quiet) is “clean” it will clear the log before writing. This is ignored if a custom log name is not specified, won’t overwrite the default “scripts.log” file.
The last parameter is a custom name of log source. If not specified, it defaults to “scripts” (.log will be appended).
The custom name affects both the tag in the system log (for high-level log messages) and the name of the custom log file.
Example: logr start verbose logger_test
logr verbose and logr quiet
Enables/disables STDERR output, can be called at any point in a script
logr clear
Clears a custom log (ignored if using the default “scripts” log)
logr [level] MESSAGE
level can be one of debug, info, log, notice, warn, error, or emerg
debug and info levels go to custom log with <DEBUG> or <INFO> indicator, but not to /var/logs/system.log.
debug level shows full function stack separated by /, so if it’s inside of a function called from another function, you can see the backtrace, e.g. logger_test:nested_func\script_func\main
  # Oct 26 08:47:17  logger_test:nested_func\script_func\main[28953] <Debug>: debug message from inside nested function calls
error, warn, and notice go to custom log and system.log with appropriate indicator. log is an alias for notice.
emerg goes to /var/log/system.log, custom log, and broadcasts a message to all logged in users.
If no level is given before MESSAGE, logr assumes info.

The script

logr.bashraw
#!/bin/bash
# Logging utility that simplifies user of bash logger command

# # First source the script
# source ~/scripts/logr.bash

# # Start the logger, generates log name from scripts filename
# logr start
# # or define your own
# logr start LOG_NAME
#
# logr [log|notice|info|debug|warn|error] MESSAGE
# # or default to "user.info" facility
# logr MESSAGE
__logr_DEFAULT_LOG_DIR="${HOME}/logs"
__logr_DEFAULT_LOG="scripts"

unset __logr_LOG_NAME
unset __logr_SCRIPT_LOG
unset __logr_VERBOSE
logr() {
	[[ -z $__logr_LOG_DIR ]] && __logr_LOG_DIR=$__logr_DEFAULT_LOG_DIR
	# default to "user" facility, can be set to local[0-9], etc.
	[[ -z $__logr_FACILITY ]] && __logr_FACILITY=user
	# default to quiet, no output to STDERR
	[[ -z $__logr_VERBOSE ]] && __logr_VERBOSE=false
	# default log tag and filename to "scripts", changed via logr start command
	[[ -z "${__logr_LOG_NAME}" ]] && __logr_LOG_NAME=$__logr_DEFAULT_LOG
	[[ -z "${__logr_SCRIPT_LOG}" ]] && __logr_SCRIPT_LOG="${__logr_LOG_DIR%/}/${__logr_LOG_NAME}.log"

	local function_name="${FUNCNAME[1]}"
	local log_type=$1


	# start must be called first, initializes logging, sets global log file
	# param 1: (string, optional) [verbose|quiet], verbose echos to STDERR, defaults to quiet
	# param 2: (string, optional) name of log source, defaults to "scripts" (.log will be appended)
	if [[ $log_type == "start" ]]; then
		local should_clean=false
		mkdir -p "${HOME}/logs/"
		if [[ $2 =~ (^-v$|^verbose$) ]]; then
			__logr_VERBOSE=true
			shift
		elif [[ $2 =~ (^-q$|^quiet$) ]]; then
			__logr_VERBOSE=false
			shift
		else
			__logr_VERBOSE=false
		fi

		if [[ $2 =~ clea[nr] ]]; then
			should_clean=true
			shift
		fi

		if [[ -n "$2" ]]; then
			__logr_LOG_NAME=$2
		fi

		__logr_SCRIPT_LOG="${HOME}/logs/${__logr_LOG_NAME}.log"
		touch $__logr_SCRIPT_LOG
		$should_clean && logr clear
		__logr_exec info $__logr_LOG_NAME "====> BEGIN LOGGING"
	# logr quiet => disables STDERR output
	elif [[ $log_type == "quiet" ]]; then
		__logr_VERBOSE=false
	# logr verbose => enables STDERR output
	elif [[ $log_type == "verbose" ]]; then
		__logr_VERBOSE=true
	# logr clear => clears the log (unless it's the default log)
	elif [[ $log_type == "clear" && $__logr_LOG_NAME != $__logr_DEFAULT_LOG ]]; then
		[[ -n $__logr_SCRIPT_LOG && -f $__logr_SCRIPT_LOG ]] && echo -n > $__logr_SCRIPT_LOG
	# debug type shows full function stack
	elif [[ $log_type == "debug" ]]; then
		function_name=$(IFS="\\"; echo "${FUNCNAME[*]:1}")
		__logr_exec debug "${__logr_LOG_NAME}:${function_name}" "${*:2}"
	# log, notice, info, warn, error set logging level
	# warn and error go to /var/log/system.log as well as logfile
	elif [[ $log_type =~ ^(notice|log|info|warn(ing)?|err(or)?|emerg) ]]; then
		local level
		case $log_type in
			notice|log) level="notice" ;;
			info) level="info" ;;
			warn*) level="warning" ;;
			err*) level="err" ;;
			emerg) level="emerg" ;;
			*) level="info" ;;
		esac
		__logr_exec $level "${__logr_LOG_NAME}:${function_name}" "${*:2}"
	# if no type is given, assumes info level
	else
		__logr_exec info "${__logr_LOG_NAME}:${function_name}" "${*:1}"
	fi
}

# execute the logger command
# param 1: (string) [log|notice|info|debug|warn|error] log level
# param 2: (string) Tag
# param 3: (string) Message
__logr_exec() {
	local cmd
	if [[ $__logr_VERBOSE == true ]]; then
		logger -p ${__logr_FACILITY}.$1 -t $2 -s $3 2>&1 | tee -a ${__logr_SCRIPT_LOG} 1>&2
	else
		logger -p ${__logr_FACILITY}.$1 -t $2 -s $3 2>> ${__logr_SCRIPT_LOG}
	fi
}

Demo

logrtest.shraw
#!/bin/bash
# Source the script file
source ~/scripts/logr.bash

script_func() {
    logr warn "$*"
    nested_func
}

nested_func() {
    logr debug "debug shows function stack separated by /"
    # Oct 26 08:47:17  logger_test:nested_func\script_func\main[28953] <Debug>: debug shows function stack separated by /
}

logr start verbose logger_test
# This sets the global $__logr_LOG_NAME to "logger_test"
# Which in turn sets the $__logr_SCRIPT_LOG, in this case "~/logs/logger_test.log"
# can include "quiet" or "verbose" to toggle STDERR output, and/or "clean" to clear the log on start

# logr clear
## clear will empty the specified log in ~/logs

logr info "Just some info (does not go to system.log)"
# Oct 26 08:47:17  logger_test:main[28942] <Info>: Just some info (does not go to system.log)
logr "No level assumes info"
logr info It also works without quoting, if special characters are quoted
logr info Special characters include \", \`, \', \$, \?, \&, \!, \$, \[\\\], etc.
# Oct 26 08:47:17  logger_test:main[28943] <Info>: No level assumes info
# Oct 26 08:47:17  logger_test:main[28944] <Info>: It also works without quoting, if special characters are quoted
# Oct 26 08:47:17  logger_test:main[28945] <Info>: Special characters include ", `, ', $, ?, &, !, $, [\], etc.

logr quiet
# Nothing after logr quiet will go to STDERR, but still goes to script log and system.log
logr debug A debug message does not go to system.log
# Oct 26 08:47:17  logger_test:main[28947] <Debug>: A debug message does not go to system.log

logr notice "notice goes to both system log and script log"
# Oct 26 08:47:17  logger_test:main[28948] <Notice>: notice goes to both system log and script log

logr warn "A WARNING: Everything higher than notice goes to syslog"
# Oct 26 08:47:17  logger_test:main[28949] <Warning>: A WARNING: Everything higher than notice goes to syslog

logr error "Uh oh, an error... that definitely goes to syslog"
# Oct 26 08:47:17  logger_test:main[28950] <Error>: Uh oh, an error... that definitely goes to syslog

logr emerg "Emergency logs to all logs, and broadcasts to all users"
# Even scripts running in the background under another user will cause a message to be shown to any user with a terminal open

script_func "This message comes from inside a function, note the :script_func tag instead of :main"
# Oct 26 08:47:17  logger_test:script_func[28951] <Warning>: This message comes from inside a function, note the :script_func tag instead of :main

Demo output

On the command line:

Oct 26 11:42:21  logger_test[61091] <Info>: ====> BEGIN LOGGING
Oct 26 11:42:21  logger_test:main[61093] <Info>: Just some info (does not go to system.log)
Oct 26 11:42:21  logger_test:main[61095] <Info>: No level assumes info
Oct 26 11:42:21  logger_test:main[61097] <Info>: It also works without quoting, if special characters are quoted
Oct 26 11:42:21  logger_test:main[61099] <Info>: Special characters include ", `, ', $, ?, &, !, $, [\], etc.

Broadcast Message from root@pibble.local
        (no tty) at 11:42 CDT...

Emergency logs to all logs, and broadcasts to all users

In ~/logs/logger_test.log:

Oct 26 11:42:21  logger_test[61091] <Info>: ====> BEGIN LOGGING
Oct 26 11:42:21  logger_test:main[61093] <Info>: Just some info (does not go to system.log)
Oct 26 11:42:21  logger_test:main[61095] <Info>: No level assumes info
Oct 26 11:42:21  logger_test:main[61097] <Info>: It also works without quoting, if special characters are quoted
Oct 26 11:42:21  logger_test:main[61099] <Info>: Special characters include ", `, ', $, ?, &, !, $, [\], etc.
Oct 26 11:42:21  logger_test:main[61102] <Debug>: A debug message does not go to system.log
Oct 26 11:42:21  logger_test:main[61103] <Notice>: notice goes to both system log and script log
Oct 26 11:42:21  logger_test:main[61104] <Warning>: A WARNING: Everything higher than notice goes to syslog
Oct 26 11:42:21  logger_test:main[61105] <Error>: Uh oh, an error... that definitely goes to syslog
Oct 26 11:42:21  logger_test:main[61106] <Emergency>: Emergency logs to all logs, and broadcasts to all users
Oct 26 11:42:21  logger_test:script_func[61108] <Warning>: This message comes from inside a function, note the :script_func tag instead of :main
Oct 26 11:42:21  logger_test:nested_func\script_func\main[61110] <Debug>: debug shows function stack separated by /

Hopefully this is useful. Let me know if you have ideas, improvements, or issues.

Speaking of logr…

Related Projects