Script Debugging

The script terminates cleanly and leaves no trace behind. How to find out it is producing the wrong result is a separate question.

Two features make debugging shell scripts hard. First, what actually runs is mostly not the shell itself but the programs it calls; second, expansion rules can make the result different from the text that was written. The second point is decisive: you cannot know what the line rm "$dir/$name" deletes without seeing how the shell expanded that line.

This lesson’s tools make exactly that expanded form visible.

Checking Without Running

bash -n parses the script but runs no command. It was introduced in the Script Anatomy lesson; it is the first step for scripts that contain destructive operations.

The script under test, broken.sh, contains an unclosed condition:

#!/usr/bin/env bash
# log summary — contains a syntax error
log="$1"

if [ -f "$log" ]; then
  echo "line count: $(wc -l < "$log")"

bash -n broken.sh

broken.sh: line 7: syntax error: unexpected end of file from `if' command on line 5

The error message gives two line numbers: where the problem was noticed, and where the structure that stayed open began. The second is usually more useful.

-n sees only syntax. Nonexistent commands, wrong options, undefined variables, and logic errors pass this check. A script coming out clean with bash -n does not mean it will run.

Trace Mode

The set -x option writes every command to standard error after expansions and before execution. It can also be turned on for the whole script with bash -x script.

bash -x extract.sh

+ log=access.log
+ count=3
+ top_paths access.log 3
+ cut '-d ' -f7 access.log
+ sort
+ uniq -c
+ sort -k1,1nr
+ head -3

Three pieces of information are visible here. The variables took their expected values. The function was called with the arguments access.log and 3. The pipeline’s links were listed separately, and the 3 in the head -3 line is the variable’s expanded form.

Notice the '-d ' notation on the fourth line: the shell shows arguments that require quoting inside quotes in the trace output. This is the most direct evidence for whether an argument containing a space really passed through as a single piece.

Formatting the Trace Prompt

The default + prefix does not say which line is running in a long script. The PS4 variable sets this prefix, and it is expanded before every line is printed.

export PS4='+ ${BASH_SOURCE##*/}:${LINENO}:${FUNCNAME[0]:-main}: '
bash -x extract.sh

+ extract.sh:2:main: log=access.log
+ extract.sh:3:main: count=3
+ extract.sh:7:main: top_paths access.log 3
+ extract.sh:5:top_paths: cut '-d ' -f7 access.log
+ extract.sh:5:top_paths: sort
+ extract.sh:5:top_paths: uniq -c
+ extract.sh:5:top_paths: sort -k1,1nr
+ extract.sh:5:top_paths: head -3

Every line now carries the file name, line number, and function name. The PS4 assignment is written inside single quotes: the variables must expand not at assignment time, but each time a trace line is written.

FUNCNAME[0] is undefined at the top level; the :-main default value makes it work under set -u as well.

Selective Tracing

Tracing the whole of a long script leaves the line you are looking for buried inside thousands of lines of output. With the set -x / set +x pair, only the section of interest is traced.

#!/usr/bin/env bash
echo "untraced section"
set -x
code=404
class="${code:0:1}"
set +x
echo "result: ${class}xx"

untraced section
+ code=404
+ class=4
+ set +x
result: 4xx

The closing line falls into the trace output too; the closing itself is a command being executed.

Separating the Trace

Trace output goes to standard error. Since the script’s warnings go there too, the two get mixed, and in a scheduled job that logs the script’s output, it becomes unreadable.

The BASH_XTRACEFD variable redirects the trace to a different descriptor:

#!/usr/bin/env bash
exec 9> trace.log
BASH_XTRACEFD=9
set -x
code=404
class="${code:0:1}"
set +x
echo "report output: ${class}xx"

report output: 4xx

trace.log contents:

+ code=404
+ class=4
+ set +x

Only the report itself landed on the terminal. The pattern of opening a descriptor with exec, introduced in the Redirection lesson, finds its use here: numbers 3 and above are free for this kind of use.

Verbose Mode

set -v writes commands before expansion, as they appear in the source file.

#!/usr/bin/env bash
set -v
code=404
echo "class: ${code:0:1}xx"

code=404
echo "class: ${code:0:1}xx"
class: 4xx

-x shows the expanded form, -v shows the written form. When both are turned on together, an expansion’s input and output are seen side by side; this is the most direct diagnostic route when expansion rules are misunderstood.

The Hook That Runs Before Every Command

trap ... DEBUG runs before every simple command. The BASH_COMMAND variable holds the text of the command about to be executed.

#!/usr/bin/env bash
trap 'printf "[%s] %s\n" "$LINENO" "$BASH_COMMAND" >&2' DEBUG
code=404
class="${code:0:1}"
echo "result: ${class}xx"

[3] code=404
[4] class="${code:0:1}"
[5] echo "result: ${class}xx"
result: 4xx

The DEBUG hook provides something set -x cannot: its body can be arbitrary code. Stopping when a specific variable jumps to an unexpected value, or printing a variable’s value before every command, is done this way.

The cost is cost itself: the hook runs for every command. It is not left in production scripts.

Inspecting Variables

declare -p prints a variable’s type and content in a reusable form. echo is not enough for arrays; declare -p shows element boundaries.

codes=(200 404 500)
declare -A counts=([404]=4 [500]=3)
declare -p codes counts

declare -a codes=([0]="200" [1]="404" [2]="500")
declare -A counts=([404]="4" [500]="3" )

-a shows the indexed array, -A the associative one. Only in this output can you see that indices skip in a sparse array, or that an empty element is genuinely empty.

Reading the Call Stack

Bash keeps the call chain in three parallel arrays: FUNCNAME holds function names, BASH_SOURCE file names, BASH_LINENO call lines. Printing these in an error handler shows where the error came from.

where() {
  local i
  for (( i = 1; i < ${#FUNCNAME[@]}; i++ )); do
    printf '  %s() <- %s:%s\n' "${FUNCNAME[i]}" "${BASH_SOURCE[i]}" "${BASH_LINENO[i-1]}"
  done
}
inner() { where; }
outer() { inner; }
outer

  inner() <- ./stack.sh:8
  outer() <- ./stack.sh:9
  main() <- ./stack.sh:10

The chain is read from the inside out: the call to where came from inside inner, the call to inner from outer, the call to outer from the top level. The index shift (BASH_LINENO[i-1]) is deliberate; the three arrays hold different facets of the same event with different alignments.

When this function is added to the ERR hook set up in the previous lesson, the script reports not only the error’s line but also its call path.

A Method

The order of the tools also gives a method for debugging:

1. Get the syntax past bash -n.
2. Add the strict mode header; most errors become visible on their own.
3. Narrow down which section the problem is in — placing a temporary exit at the end of a section and bisecting is the fastest way.
4. Trace the narrowed-down section with set -x and add location information with PS4.
5. If you are looking for a difference between an expansion’s input and output, turn it on together with -v.
6. Print complex data structures with declare -p.

This order puts the cheapest tool first. A session that starts with set -x can end up spending its time hunting for a syntax error that bash -n would have found in a second.

Summary

• bash -n checks only syntax; it does not run the script and does not see logic errors.
• set -x writes every command after expansions; it is direct evidence of whether quoting is working correctly.
• PS4 sets the trace prefix and is re-expanded for every line; it must be assigned inside single quotes.
• BASH_XTRACEFD sends trace output to a separate descriptor, separating it from the script’s own messages.
• set -v shows the written form, set -x the expanded form; used together, an expansion’s input and output can be compared.
• declare -p gives array contents with their boundaries, and FUNCNAME/BASH_SOURCE/BASH_LINENO give the call stack.

Next Step

This lesson’s tools find an error after it has occurred. Most errors in shell scripts, though, are determined before they occur: an unquoted expansion, an unchecked exit code, a non-portable option. The next lesson takes up the static analysis tool that catches this class without running the script, and puts report.sh through its inspection.