Skip to content

Commit

Permalink
Fixed that last messages are shown for the last sourced actual script…
Browse files Browse the repository at this point in the history
… and not only for a whatever-functions.sh (related to issue1875)
  • Loading branch information
jsmeix committed Jul 25, 2018
1 parent b98375d commit 2420688
Show file tree
Hide file tree
Showing 4 changed files with 38 additions and 18 deletions.
37 changes: 26 additions & 11 deletions usr/share/rear/lib/_input-output-functions.sh
Expand Up @@ -384,21 +384,36 @@ function CallerSource () {

# Error exit:
function Error () {
# ${caller_source[@]} is e.g. /usr/share/rear/output/default/200_make_prefix_dir.sh line 18
# so that $caller_source is the script where the Error function was called:
local caller_source=( $( CallerSource ) )
local caller_script_basename="$( basename $caller_source )"
# Get the last sourced script out of the log file:
# Using the CallerSource function is not sufficient here because CallerSource results
# the file where this Error function is called which can also be a lib/*-functions.sh
# but showing *-functions.sh would not be as helpful for the user as the last actual script.
# Each sourced script gets logged as 'timestamp Including sub-path/to/script_file_name.sh' and
# valid script files names are of the form NNN_script_name.sh (i.e. with leading 3-digit number)
# but also the outdated scripts with leading 2-digit number get sourced
# see the SourceStage function in lib/framework-functions.sh
# so that we grep for script files names with two or more leading numbers:
local last_sourced_script_log_entry=( $( grep -o ' Including .*/[0-9][0-9].*\.sh' $RUNTIME_LOGFILE | tail -n 1 ) )
# The last_sourced_script_log_entry contains: Including sub-path/to/script_file_name.sh
local last_sourced_script_sub_path="${last_sourced_script_log_entry[1]}"
local last_sourced_script_filename="$( basename $last_sourced_script_sub_path )"
# Do not log the error message right now but after the currenly last log messages were shown:
PrintError "ERROR: $*"
# Show some additional hopefully meaningful output on the user's terminal
# (no need to log that again here because it is already in the log file)
# in particular the normal stdout and stderr messages of the last called programs
# to make the root cause more obvious to the user without the need to analyze the log file
# cf. https://github.com/rear/rear/issues/1875#issuecomment-407039065
PrintError "Some latest log messages from the last called script $caller_script_basename:"
# Show lines after the last called script was sourced (logged as 'Including sub-path/to/script.sh')
# but at most up to a line that is usually logged as '++ Error ...' or '++ BugError ...'
# if such a line exists, otherwise 'sed' proceeds to the end.
PrintError "Some latest log messages since the last called script $last_sourced_script_filename:"
# Extract lines starting when the last script was sourced (logged as 'Including sub-path/to/script.sh')
# but do not use last_sourced_script_sub_path because it contains '/' characters that let sed fail with
# sed: -e expression #1, char ...: extra characters after command
# because the '/' characters would need to be escaped in the sed expression so that
# we simply use last_sourced_script_filename in the sed expression.
# Extract at most up to a line that is usually logged as '++ Error ...' or '++ BugError ...'
# (but do not stop at lines that are logged like '++ StopIfError ...' or '++ PrintError ...')
# if such a '+ Error' or '+ BugError' line exists, otherwise 'sed' proceeds to the end
# (the sed pattern '[Bug]*Error' is fuzzy because it would also match things like 'uuggError').
# The reason to stop at a line that contains '+ .*Error ' is that in debugscripts mode '-D'
# a BugError or Error function call with a multi line error message (e.g. BugError does that)
# results 'set -x' debug output of that function call in the log file that looks like:
Expand All @@ -411,10 +426,10 @@ function Error () {
# so that those debug output lines are indistinguishable from normal stdout/stderr output of programs,
# cf. https://github.com/rear/rear/pull/1877
# Thereafter ('+ .*Error ' lines were needed above) skip 'set -x' lines (lines that start with a '+' character).
# Show at most the last 5 lines because more older stuff may cause more confusion than help.
# Show at most the last 8 lines because more older stuff may cause more confusion than help.
# Add two spaces indentation for better readability what those log file lines are.
# Some messages could be too long to be usefully shown on the user's terminal so that they are truncated after 200 bytes:
PrintError "$( sed -n -e "/Including .*$caller_script_basename/,/+ .*Error /p" $RUNTIME_LOGFILE | grep -v '^+' | tail -n 5 | sed -e 's/^/ /' | cut -b-200 )"
PrintError "$( sed -n -e "/Including .*$last_sourced_script_filename/,/+ [Bug]*Error /p" $RUNTIME_LOGFILE | grep -v '^+' | tail -n 8 | sed -e 's/^/ /' | cut -b-200 )"
Log "ERROR: $*"
LogToSyslog "ERROR: $*"
# TODO: I <jsmeix@suse.de> wonder if the "has_binary caller" test is still needed nowadays
Expand Down Expand Up @@ -454,7 +469,7 @@ BUG in $caller_source:
--------------------
Please report this issue at https://github.com/rear/rear/issues
and include the relevant parts from $RUNTIME_LOGFILE
preferably with full debug information via 'rear -d -D $WORKFLOW'
preferably with full debug information via 'rear -D $WORKFLOW'
===================="
}

Expand Down
15 changes: 10 additions & 5 deletions usr/share/rear/output/default/200_make_prefix_dir.sh
@@ -1,10 +1,15 @@

# Create $OUTPUT_PREFIX directory under the mounted network filesystem share.
# Create $OUTPUT_PREFIX directory.
# The $OUTPUT_PREFIX directory defaults to $HOSTNAME.
#
# This happens usually under a mounted network filesystem share
# e.g. in case of BACKUP_URL=nfs://NFS.server.IP.address/remote/nfs/share
# but it is also happens for local stuff like BACKUP_URL=usb:///dev/disk/by-label/REAR-000
#
# Do not do this for tapes and special attention for file:///path

# Generate url variable name that depends on the current stage, e.g. BACKUP_URL:
# Generate url variable name that depends on the current stage,
# e.g. BACKUP_URL or OUTPUT_URL:
url="$( echo $stage | tr '[:lower:]' '[:upper:]' )_URL"

local scheme=$( url_scheme ${!url} )
Expand All @@ -14,9 +19,9 @@ local opath=$( output_path $scheme $path )
# If $opath is empty return silently (e.g. scheme tape):
test "$opath" || return 0

# Create $OUTPUT_PREFIX sub-directory under the mounted network filesystem share:
mkdir -p $v -m0750 "$opath" && return 0
# Create $OUTPUT_PREFIX sub-directory:
mkdir -p $v -m0750 "$opath" && return

# A failure to cerate the $OUTPUT_PREFIX sub-directory is fatal:
Error "Failed to create '$OUTPUT_PREFIX' directory under the mounted network filesystem share"
Error "Failed to create '$opath' directory for $url=${!url}"

2 changes: 1 addition & 1 deletion usr/share/rear/skel/default/etc/scripts/system-setup
Expand Up @@ -132,7 +132,7 @@ sleep 2
# Because the kernel command line option 'debug' means 'set -x' for the system setup scripts
# it also means '-D' (i.e. 'set -x') for the automated 'rear recover' run:
if rear_debug ; then
rear_debug_options='-d -D'
rear_debug_options='-D'
else
rear_debug_options=''
fi
Expand Down
Expand Up @@ -64,7 +64,7 @@ fi
# Let the user choose the backup that should be restored:
LogPrint "Select a backup archive."
# Disable printing commands and their arguments as they are executed on stderr
# which could have been enabled when running e.g. "rear -d -D recover"
# which could have been enabled when running e.g. "rear -D recover"
# to not disturb the select output which also happens on stderr.
# When 'set -x' is set even calling 'set +x 2>/dev/null' would output '+ set +x' but
# http://stackoverflow.com/questions/13195655/bash-set-x-without-it-being-printed
Expand Down

0 comments on commit 2420688

Please sign in to comment.