1.2 Interactive Line Tracing Session

One of the things I had found disappointing about the default set -x tracing behavior is that no position information is given in the trace output, in particular the line number and the file name. However with the introduction in Bash 3.0 of the introspection variables, also needed to support the debugger, one can set $PS4 to rectify this. (I became of this in a defunct blog http://raz.cx/blog/2005/08/handy-bash-debugging-trick.html.)

Here’s what I use:

  PS4='(${BASH_SOURCE}:${LINENO}): ${FUNCNAME[0]} - [${SHLVL},${BASH_SUBSHELL}, $?]
'

Note that the string is in single quotes, not double quotes and there is a newline in the string. By using single quotes, variables which have a dollar in front of them in the string are expanded in the current environment of the line that is about to be run rather than at the time the variable PS4 is set.

You might want to add this in your shell’s start-up script, e.g., .bashrc, or .profile.

There is also facility inside the bash debugger showing position information when tracing a script. Here’s a simple session.

/usr/local/bin/bashdb /tmp/fact.sh
Bourne-Again Shell Debugger, release bash-5.2-1.1.2
Copyright 2002, 2003, 2004, 2006, 2007, 2008 Rocky Bernstein
This is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.

(/tmp/fact.sh:11):
11:	echo fact 0 is: `fact 0`
bashdb<0> set linetrace on
bashdb<1> cont
(/tmp/fact.sh:11):
level 1, subshell 1, depth 0:	echo fact 0 is: `fact 0`
fact 0
(/tmp/fact.sh:2):
level 1, subshell 1, depth 1:	fact() {
(/tmp/fact.sh:3):
level 1, subshell 1, depth 1:	    local -i n=${1:0}
(/tmp/fact.sh:4):
level 1, subshell 1, depth 1:	    ((n==0)) && echo 1 && return
(/tmp/fact.sh:4):
level 1, subshell 1, depth 1:	    ((n==0)) && echo 1 && return
echo 1
(/tmp/fact.sh:4):
level 1, subshell 1, depth 1:	    ((n==0)) && echo 1 && return
return
fact 0 is: 1
(/tmp/fact.sh:13):
level 1, subshell 0, depth 0:	echo fact 3 is: $(fact 3)
(/tmp/fact.sh:13):
level 1, subshell 1, depth 0:	echo fact 3 is: $(fact 3)
fact 3
(/tmp/fact.sh:2):
level 1, subshell 1, depth 1:	fact() {
(/tmp/fact.sh:3):
level 1, subshell 1, depth 1:	    local -i n=${1:0}
(/tmp/fact.sh:4):
level 1, subshell 1, depth 1:	    ((n==0)) && echo 1 && return
(/tmp/fact.sh:5):
level 1, subshell 1, depth 1:	    ((nm1=n-1))
(/tmp/fact.sh:6):
level 1, subshell 1, depth 1:	    ((fact_nm1=`fact $nm1`))
(/tmp/fact.sh:6):
level 1, subshell 2, depth 1:	    ((fact_nm1=`fact $nm1`))
fact $nm1
(/tmp/fact.sh:2):
level 1, subshell 2, depth 2:	fact() {
...
level 1, subshell 4, depth 4:	fact() {
(/tmp/fact.sh:3):
level 1, subshell 4, depth 4:	    local -i n=${1:}
(/tmp/fact.sh:4):
level 1, subshell 4, depth 4:	    ((n==0)) && echo 1 && return
(/tmp/fact.sh:4):
level 1, subshell 4, depth 4:	    ((n==0)) && echo 1 && return
echo 1
(/tmp/fact.sh:4):
level 1, subshell 4, depth 4:	    ((n==0)) && echo 1 && return
return
(/tmp/fact.sh:7):
level 1, subshell 3, depth 3:	    ((result=n*fact_nm1))
(/tmp/fact.sh:8):
level 1, subshell 3, depth 3:	    echo $result
(/tmp/fact.sh:7):
level 1, subshell 2, depth 2:	    ((result=n*fact_nm1))
(/tmp/fact.sh:8):
level 1, subshell 2, depth 2:	    echo $result
(/tmp/fact.sh:7):
level 1, subshell 1, depth 1:	    ((result=n*fact_nm1))
(/tmp/fact.sh:8):
level 1, subshell 1, depth 1:	    echo $result
fact 3 is: 6
(/usr/local/bin/bashdb:260):
level 1, subshell 0, depth -1:
Debugged program terminated normally. Use q to quit or R to restart.
bashdb<2>

An explanation of the output. The level is how many invocations of BASH are in effect before the statement shown is executed. The subshell is how many subshells you are nested in. Subshells are used by command substitution—`..' and $(...)—as well as arithmetic expressions ((...)). The depth is the function depth or how many calls you are nested in. A “source” command also increases this depth.

Notice also that in contrast to set -x tracing, the line shown is exactly as you entered it in the source. So if you indented statements in a meaningful way, it will help you understand the statement nesting level. But as before, if a line contains multiple statements, you are not executing the first statement in the line and set showcommand is not turned off (by default it is on), that statement is shown in addition below the multi-statement line. Such an example can be seen right at the beginning where fact 0 is shown.

If what you want to do is trace the entire script as was done above (and not stop in the debugger when the script is over), you can get the same effect by using the -X or --trace option on the bashdb command:

/usr/local/bin/bashdb -X /tmp/fact.sh
Bourne-Again Shell Debugger, release bash-5.2-1.1.2
Copyright 2002, 2003, 2004, 2006, 2007, 2008, 2009, 2011 Rocky Bernstein
This is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.

(/usr/local/bin/bashdb:272):
level 1, subshell 0, depth -1:	  . $_source_file
(/tmp/fact.sh:11):
level 1, subshell 0, depth 0:	echo fact 0 is: `fact 0`
(/tmp/fact.sh:11):
level 1, subshell 1, depth 0:	echo fact 0 is: `fact 0`
fact 0
(/tmp/fact.sh:2):
level 1, subshell 1, depth 1:	fact() {
(/tmp/fact.sh:3):
level 1, subshell 1, depth 1:	    local -i n=${1:0}
...
level 1, subshell 2, depth 2:	    echo $result
(/tmp/fact.sh:7):
level 1, subshell 1, depth 1:	    ((result=n*fact_nm1))
(/tmp/fact.sh:8):
level 1, subshell 1, depth 1:	    echo $result
fact 3 is: 6
(/usr/local/bin/bashdb:285):
level 1, subshell 0, depth -1:

If you issue a break (e.g. send a SIGINT signal) while the program is running you will go into the debugger (assuming your program doesn’t trap SIGINT).