-
Notifications
You must be signed in to change notification settings - Fork 0
/
bashlogging
259 lines (228 loc) · 14.2 KB
/
bashlogging
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
#!/usr/bin/env bash
#USAGE:
# #Source the file to get access to all the variable and function definitions.
#
# #If you want a non-default LOGTYPE it must be specified before "source"ing.
# #Options: ['stdout'|'stderr'|'file'|'stdoutfile'|'stderrfile'(default)]
# LOGTYPE='stderr'
# source bashlogging
# #LOGTYPE determines where to direct logging messages. Once you've "source"d
# #bashlogging this parameter is fixed and cannot be changed.
#
# #The other two parameters are LOGFILE and LOGLEVEL, these can be set before
# #or after "source"ing bashlogging, or changed at any point to suit your needs.
# LOGFILE='path/to/mylogfile.log'
# LOGLEVEL=3 #I have a problem with my script that I need to identify.
#
# myfunc(){
# #Then all that is left is to cover your script and functions with
# #useful messages:
# debug "ENTERING: ${FUNCNAME[0]}() ; CALLED FROM: ${FUNCNAME[1]}()"
# debugcont "Called with $# arguments"
# local i=0 ; for var in "$@"; do ((++i)) ; debugcont "arg $i = ${var}"; done
# #debugcont "arg 1 = $1"
# #debugcont "arg 2 = $2"
# #debugcont "arg 3 = $3"
# debugcont "ImportantGlobalParamater = $ImportantGlobalParamater"
# inform 'That important thing is being calculated now...'
# #You can pipe another command's stdout to your logs
# command1 | err_pipe "command1: "
# #Or with the command's stderr as well
# command1 2>&1 | err_pipe "command1: "
# #If using one of the stderr or file-only LOGTYPEs, you can message mid pipe
# command1 | tee >(debug "Stuff is happening") | command2
# #Or grab errors from commands used to set varibles
# VARIABLE="$(cmd_sets_var_value 2> >(err_pipe "ASSIGN VARIABLE: "))"
# warn 'The ducks weren't all in a row, but we'll forge on.'
# err 'It all went horribly wrong, no value will be returned.'
# errcont "The value of x was $y and j was $z, try passing q to ${FUNCNAME}()"
# errcont "You may also need to 'chmod a+rwx yourfile.txt' and do a rain dance."
# }
#
# #For an example of a large bash script that makes heavy use of bashlogging, see:
# # https://github.com/stuart-knock/myth2kodi/blob/master/myth2kodi
#
#REQUIRES:
# tee -- reads from standard input then writes to standard output & files.
# xargs
# bash >= 4.2 -- for, at least, the '-g' flag to declare.
# GNU sleep -- supporting specification of floating point seconds ie, 0.1 etc.
#
#PROVIDES:
# #Message functions: for file output, prepends date & time
# debug -- For LOGLEVEL >= 3, writes messages prepended with "DEBUG: "
# inform -- For LOGLEVEL >= 2, writes messages prepended with "INFORM: "
# warn -- For LOGLEVEL >= 1, writes messages prepended with "WARNING: "
# err -- For LOGLEVEL >= 0, writes messages prepended with "ERROR: "
# #Continued/multiline message functions: these are indented without leading info.
# debugcont -- Continues a LOGLEVEL 3 message.
# informcont -- Continues a LOGLEVEL 2 message.
# warncont -- Continues a LOGLEVEL 1 message.
# errcont -- Continues a LOGLEVEL 0 message.
# #Pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
# err_pipe -- For LOGLEVEL >= 0, write piped input to logs.
#
#DESCRIPTION:
# Defines several functions for fine grained control of logging information.
# Writes different types of messages based on LOGLEVEL. The messages are
# sent to either stdout, stderr, file, or both based on the LOGTYPE parameter.
# The file output is prepended with date & time -- stdout/stderr aren't.
#
# Author: Stuart A. Knock
# Originally Written: 2015-11-27
# https://github.com/stuart-knock/bash-tools
#
#TODO: Consider adding an AutoElevate ['Enabled'|'Disabled'] option, which automatically raises
# the LOGLEVEL to 2 in the event of warnings and 3 in the event of errors.
#TODO: Consider making indentation on Cont[inuation] lines a standard 4 spaces.
#TODO: Enable different "LOGLEVEL"s for file and stdout/stderr.
#TODO: the fraction of a second sleep works for GNU/Linux sleep, but not necessarily others... Solve order preservation some other way...
#TODO: Consider copying stderr generated by the script to log file: see http://stackoverflow.com/questions/637827/redirect-stderr-and-stdout-in-a-bash-script
# exec 4>&2 2> >(tee >(xargs --null printf "[$(date +%FT%T)] ERROR: %s\\n" >> "$LOGFILE") >&4)
#TODO: Consider whether it's worth making the functions readonly to avoid accidental modification.
#Default logging level, controls the type of bashlogging messages reported.
#This can be modified at any point in a calling script to increase/decrease
#the amount of information reported based on context.
# 0=Only Errors;
# 1=adds warnings;
# 2=adds more information;
# 3=provides debugging output.
if [[ -z "$LOGLEVEL" ]]; then declare -gi LOGLEVEL=2; else declare -gi LOGLEVEL; fi
#Default log file name, only set if one isn't already
[[ -z "$LOGFILE" ]] && LOGFILE='default_bashlogging.log'
#Default type of logging to do, or more specifically the type of destination
#for logging messages.
#Options: ['file'|'stdout'|'stderr'|'filestdout'|'filestderr'(default)]
#The default set here can only be overridden before source[ing] bashlogging, and
#not after sourcing, as can be done with LOGLEVEL and LOGFILE.
if [[ -z "$LOGTYPE" ]]; then declare -gr LOGTYPE='filestderr'; else declare -gr LOGTYPE; fi
#^^^^----------- DEFAULT USER SETTINGS ABOVE THIS LINE ------------------^^^^#
declare -gr pad=' ' #needs to be >= number of spaces for the largest X below in %0.Xs
declare -gr DEBUG_CLR='\e[1;32mDEBUG:\e[0m' # Bold Green
declare -gr INFO_CLR='\e[1;34mINFO:\e[0m' # Bold Blue
declare -gr WARN_CLR='\e[1;33mWARNING:\e[0m' # Bold Yellow-ish
declare -gr ERROR_CLR='\e[1;31mERROR:\e[0m' # Bold Red
declare -gr STRIP_CLR='s/\x1B\[([0-1];)?[0-4]{1,2}m//g' #A regex to strip colour tags
#Return an error message if LOGTYPE isn't set correctly.
if [[ ! "$LOGTYPE" =~ ^(logfile|file|stdout|stderr|both|filestdout|filestderr)$ ]]; then
printf "$ERROR_CLR %s\\n" "For ${BASH_SOURCE[0]} LOGTYPE must be ['file'|'stdout'|'stderr'|'filestdout'|'filestderr'(default)]."
return 1
fi
if [[ "$LOGTYPE" = @(both|filestdout) ]] ; then
#Functions defining the different logging messages, sent to logfile & stdout.
#sleep is a hack to avoid wrong order in file when *Cont is used, and apparently processes faster leading to out of order file content.
debug(){ ((LOGLEVEL >= 3)) && printf "$DEBUG_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE"); sleep 0.002; }
inform(){ ((LOGLEVEL >= 2)) && printf "$INFO_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE"); sleep 0.002; }
warn(){ ((LOGLEVEL >= 1)) && printf "$WARN_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE"); sleep 0.002; }
err(){ ((LOGLEVEL >= 0)) && printf "$ERROR_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE"); sleep 0.002; }
#Func: #If LOGLEVEL appropriate #Prepend msg with Type #Pipe to stdout & process substitution: prepend Date&Time, strip colour tags #Redirect to file #Wait so order preserved
#Use for multiple lines of a single message, sent to logfile & stdout
debugcont(){ ((LOGLEVEL >= 3)) && printf '%0.7s%s\n' "$pad" "$1" | tee -a "$LOGFILE"; }
informcont(){ ((LOGLEVEL >= 2)) && printf '%0.6s%s\n' "$pad" "$1" | tee -a "$LOGFILE"; }
warncont(){ ((LOGLEVEL >= 1)) && printf '%0.9s%s\n' "$pad" "$1" | tee -a "$LOGFILE"; }
errcont(){ ((LOGLEVEL >= 0)) && printf '%0.7s%s\n' "$pad" "$1" | tee -a "$LOGFILE"; }
#Use to pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
err_pipe(){ while IFS='' read -r msg; do msg="$1$msg"; ((LOGLEVEL >= 0)) && printf '%s\n' "$msg" | tee -a "$LOGFILE"; done; }
elif [[ "$LOGTYPE" = 'filestderr' ]] ; then
#Functions defining the different logging messages, sent to logfile & stderr.
#sleep is a hack to avoid wrong order in file when *Cont is used, and apparently processes faster leading to out of order file content.
debug(){ ((LOGLEVEL >= 3)) && printf "$DEBUG_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE") 1>&2 ; sleep 0.002; }
inform(){ ((LOGLEVEL >= 2)) && printf "$INFO_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE") 1>&2 ; sleep 0.002; }
warn(){ ((LOGLEVEL >= 1)) && printf "$WARN_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE") 1>&2 ; sleep 0.002; }
err(){ ((LOGLEVEL >= 0)) && printf "$ERROR_CLR %s\\n" "$1" | tee >(xargs --null printf "[$(date +%FT%T)] %s" | sed -r "$STRIP_CLR" >> "$LOGFILE") 1>&2 ; sleep 0.002; }
#Func: #If LOGLEVEL appropriate #Prepend msg with Type #Pipe to stderr & process substitution: prepend Date&Time, strip colour tags #Redirect to file #Wait so order preserved
#Use for multiple lines of a single message, sent to logfile & stderr
debugcont(){ ((LOGLEVEL >= 3)) && printf '%0.7s%s\n' "$pad" "$1" | tee -a "$LOGFILE" 1>&2 ; }
informcont(){ ((LOGLEVEL >= 2)) && printf '%0.6s%s\n' "$pad" "$1" | tee -a "$LOGFILE" 1>&2 ; }
warncont(){ ((LOGLEVEL >= 1)) && printf '%0.9s%s\n' "$pad" "$1" | tee -a "$LOGFILE" 1>&2 ; }
errcont(){ ((LOGLEVEL >= 0)) && printf '%0.7s%s\n' "$pad" "$1" | tee -a "$LOGFILE" 1>&2 ; }
#Use to pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
err_pipe(){ while IFS='' read -r msg; do msg="$1$msg"; ((LOGLEVEL >= 0)) && printf '%s\n' "$msg" | tee -a "$LOGFILE" 1>&2 ; done; }
elif [[ "$LOGTYPE" = 'stdout' ]] ; then
#Functions defining the different logging messages, no-logfile==only-stdout
debug(){ ((LOGLEVEL >= 3)) && printf "$DEBUG_CLR %s\\n" "$1" ; }
inform(){ ((LOGLEVEL >= 2)) && printf "$INFO_CLR %s\\n" "$1" ; }
warn(){ ((LOGLEVEL >= 1)) && printf "$WARN_CLR %s\\n" "$1" ; }
err(){ ((LOGLEVEL >= 0)) && printf "$ERROR_CLR %s\\n" "$1" ; }
#Use for multiple lines of a single message, no-logfile==only-stdout
debugcont(){ ((LOGLEVEL >= 3)) && printf '%0.7s%s\n' "$pad" "$1" ; }
informcont(){ ((LOGLEVEL >= 2)) && printf '%0.6s%s\n' "$pad" "$1" ; }
warncont(){ ((LOGLEVEL >= 1)) && printf '%0.9s%s\n' "$pad" "$1" ; }
errcont(){ ((LOGLEVEL >= 0)) && printf '%0.7s%s\n' "$pad" "$1" ; }
#Use to pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
err_pipe(){ while IFS='' read -r msg; do msg="$1$msg"; ((LOGLEVEL >= 0)) && printf '%s\n' "$msg" ; done; }
elif [[ "$LOGTYPE" = 'stderr' ]] ; then
#Functions defining the different logging messages, no-logfile==only-stderr
debug(){ ((LOGLEVEL >= 3)) && printf "$DEBUG_CLR %s\\n" "$1" 1>&2 ; }
inform(){ ((LOGLEVEL >= 2)) && printf "$INFO_CLR %s\\n" "$1" 1>&2 ; }
warn(){ ((LOGLEVEL >= 1)) && printf "$WARN_CLR %s\\n" "$1" 1>&2 ; }
err(){ ((LOGLEVEL >= 0)) && printf "$ERROR_CLR %s\\n" "$1" 1>&2 ; }
#Use for multiple lines of a single message, no-logfile==only-stderr
debugcont(){ ((LOGLEVEL >= 3)) && printf '%0.7s%s\n' "$pad" "$1" 1>&2 ; }
informcont(){ ((LOGLEVEL >= 2)) && printf '%0.6s%s\n' "$pad" "$1" 1>&2 ; }
warncont(){ ((LOGLEVEL >= 1)) && printf '%0.9s%s\n' "$pad" "$1" 1>&2 ; }
errcont(){ ((LOGLEVEL >= 0)) && printf '%0.7s%s\n' "$pad" "$1" 1>&2 ; }
#Use to pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
err_pipe(){ while IFS='' read -r msg; do msg="$1$msg"; ((LOGLEVEL >= 0)) && printf '%s\n' "$msg" 1>&2 ; done; }
elif [[ "$LOGTYPE" = @(logfile|file) ]] ; then
#Functions defining the different logging messages, no-stdout|stderr==only-logfile
debug(){ ((LOGLEVEL >= 3)) && printf "[$(date +%FT%T)] DEBUG: %s\\n" "$1" >> "$LOGFILE"; }
inform(){ ((LOGLEVEL >= 2)) && printf "[$(date +%FT%T)] INFO: %s\\n" "$1" >> "$LOGFILE"; }
warn(){ ((LOGLEVEL >= 1)) && printf "[$(date +%FT%T)] WARNING: %s\\n" "$1" >> "$LOGFILE"; }
err(){ ((LOGLEVEL >= 0)) && printf "[$(date +%FT%T)] ERROR: %s\\n" "$1" >> "$LOGFILE"; }
#Use for multiple lines of a single message, no-stdout==only-logfile
debugcont(){ ((LOGLEVEL >= 3)) && printf '%0.7s%s\n' "$pad" "$1" >> "$LOGFILE"; }
informcont(){ ((LOGLEVEL >= 2)) && printf '%0.6s%s\n' "$pad" "$1" >> "$LOGFILE"; }
warncont(){ ((LOGLEVEL >= 1)) && printf '%0.9s%s\n' "$pad" "$1" >> "$LOGFILE"; }
errcont(){ ((LOGLEVEL >= 0)) && printf '%0.7s%s\n' "$pad" "$1" >> "$LOGFILE"; }
#Use to pipe output from another command to logs, eg: command 2>&1 | err_pipe "command: "
err_pipe(){ while IFS='' read -r msg; do msg="$1$msg"; ((LOGLEVEL >= 0)) && printf '%s\n' "$msg" >> "$LOGFILE"; done; }
else
printf "$ERROR_CLR %s\\n" 'The LOGTYPE option, if provided, must be one of: "file"; "stdout"; "stderr"; "filestdout"; "filestderr".'
return 1
fi
# #TODO: Check this actually works... seems like a good idea...
#USAGE:
# set_trace 'Detailed' "$m2kdir/${FileNameNow}_debug_trace.log"
#Set debug trace, output to its own file via file-descriptor trace_fd,
#which should be assigned the lowest value of an available fd > 10.
set_trace(){
local pre
local file_name
local trace_fd
#Take prepend setting from command, default to "Simple".
if [[ -n "$1" ]]; then pre="$1"; else pre='Simple'; fi
#Send trace output to file
if [[ -n "$2" ]]; then
file_name="$2"
else
file_name="$(date +%FT%H%M%S)_debug_trace.log"
fi
exec {trace_fd}>"$file_name"
BASH_XTRACEFD="$trace_fd"
#Prepend output with a "Simple" OR "Detailed"
if [[ "$pre" = "Simple" ]]; then
PS4='${0}:${LINENO}: '
elif [[ "$pre" = "Detailed" ]]; then
PS4='(${BASH_SOURCE}:${LINENO}): ${FUNCNAME[0]} - [${SHLVL},${BASH_SUBSHELL}, $?]'$'\n'
else
{ printf "$ERROR_CLR %s\\n" "Prepend arg must be ['Simple' | 'Detailed'] eg: ${BASH_SOURCE[0]} 'Detailed'" ; return 1 ; }
fi
set -x
}
#Unset the debug trace, closing file-descriptor trace_fd.
unset_trace(){
#Close trace_fd
#exec {trace_fd}<&-
unset BASH_XTRACEFD #unsetting BASH_XTRACEFD has the side effect of closing the file-descriptor it had been pointed to...
}
# #Make the functions defined here readonly to prevent clobbering by calling script.
# readonly -f debug
# readonly -f inform
# readonly -f warn
# readonly -f err
# readonly -f debugcont
# readonly -f informcont
# readonly -f warncont
# readonly -f errcont
return 0