Differences
This shows you the differences between two versions of the page.
Both sides previous revision Previous revision Next revision | Previous revision | ||
scripting:debuggingtips [2011/06/04 15:12] thebonsai crosslink variables |
scripting:debuggingtips [2017/06/07 02:42] (current) fgrose [Making xtrace more useful] set variables with descriptive words |
||
---|---|---|---|
Line 3: | Line 3: | ||
{{keywords>bash shell scripting bug debug debugging}} | {{keywords>bash shell scripting bug debug debugging}} | ||
- | These few lines are not intended as a full-fledged debugging tutorial, but as assorted hints and comments about debugging a Bash script. | + | These few lines are not intended as a full-fledged debugging tutorial, but as hints and comments about debugging a Bash script. |
Line 9: | Line 9: | ||
===== Use a unique name for your script ===== | ===== Use a unique name for your script ===== | ||
- | Do **not** name your script ''test'', for example! //Why?// ''test'' is already a UNIX(r)-command, and __most likely built into your shell__ (it's a built-in in Bash) - so you won't be able to run a script with the name ''test'' in a normal way. | + | Do **not** name your script ''test'', for example! //Why?// ''test'' is the name of a UNIX(r)-command, and __most likely built into your shell__ (it's a built-in in Bash) - so you won't be able to run a script with the name ''test'' in a normal way. |
**Don't laugh!** This is a classic mistake :-) | **Don't laugh!** This is a classic mistake :-) | ||
Line 17: | Line 17: | ||
Many people come into IRC and ask something like //"Why does my script fail? I get an error!"//. And when you ask them what the error message is, they don't even know. Beautiful. | Many people come into IRC and ask something like //"Why does my script fail? I get an error!"//. And when you ask them what the error message is, they don't even know. Beautiful. | ||
- | Reading and interpreting error messages is 50% of your job as debugger! Error messages actually **mean** something, and at the very least they can give you hints as to where to start your further debugging. **READ YOUR ERROR MESSAGES!** | + | Reading and interpreting error messages is 50% of your job as debugger! Error messages actually **mean** something. At the very least, they can give you hints as to where to start debugging. **READ YOUR ERROR MESSAGES!** |
- | You may ask yourself why this is mentioned as debugging tip? Well, __you would be surprised how many shell users ignore the text of error messages!__ When I find some time, I'll paste 2 or 3 IRC log-snips here, just to show you that annoying fact. | + | You may ask yourself why is this mentioned as debugging tip? Well, __you would be surprised how many shell users ignore the text of error messages!__ When I find some time, I'll paste 2 or 3 IRC log-snips here, just to show you that annoying fact. |
Line 25: | Line 25: | ||
===== Use a good editor ===== | ===== Use a good editor ===== | ||
- | Your choice of editor is a matter of personal preference, but you should use one **with Bash syntax highlighting**! Syntax highlighting helps you see (you guessed it ...) syntax errors, such as unclosed quotes and braces, or typos. | + | Your choice of editor is a matter of personal preference, but one with **Bash syntax highlighting** is highly recommended! Syntax highlighting helps you see (you guessed it) syntax errors, such as unclosed quotes and braces, typos, etc. |
From my personal experience, I can suggest ''vim'' or ''GNU emacs''. | From my personal experience, I can suggest ''vim'' or ''GNU emacs''. | ||
Line 31: | Line 31: | ||
===== Write logfiles ===== | ===== Write logfiles ===== | ||
- | For more complex scripts, it's useful to write a logfile or even log to syslog. Nobody can debug something without knowing what actually happens and what breaks. | + | For more complex scripts, it's useful to write to a log file, or to the system log. Nobody can debug your script without knowing what actually happened and what went wrong. |
- | A possible syslog interface is ''logger'' ([[http://unixhelp.ed.ac.uk/CGI/man-cgi?logger+1 | online manpage]]). | + | An available syslog interface is ''logger'' ([[http://unixhelp.ed.ac.uk/CGI/man-cgi?logger+1 | online manpage]]). |
Line 42: | Line 42: | ||
Insert **echos** everywhere you can, and print to ''stderr'': | Insert **echos** everywhere you can, and print to ''stderr'': | ||
<code> | <code> | ||
- | echo "DEBUG: current I=$I" >&2 | + | echo "DEBUG: current i=$i" >&2 |
</code> | </code> | ||
Line 48: | Line 48: | ||
<code> | <code> | ||
- | FOO_PID=$(< fooservice.pid) | + | pid=$(< fooservice.pid) |
- | echo "DEBUG: read from file: FOO_PID=\"$FOO_PID\"" >&2 | + | echo "DEBUG: read from file: pid=\"$pid\"" >&2 |
</code> | </code> | ||
Bash's [[commands:builtin:printf | printf]] command has the ''%q'' format, which is handy for verifying whether strings are what they appear to be. | Bash's [[commands:builtin:printf | printf]] command has the ''%q'' format, which is handy for verifying whether strings are what they appear to be. | ||
<code> | <code> | ||
- | FOO=$(< inputfile) | + | foo=$(< inputfile) |
- | printf "DEBUG: FOO is |%q|\n" "$FOO" >&2 | + | printf "DEBUG: foo is |%q|\n" "$foo" >&2 |
# exposes whitespace (such as CRs, see below) and non-printing characters | # exposes whitespace (such as CRs, see below) and non-printing characters | ||
</code> | </code> | ||
Line 64: | Line 64: | ||
* ''set -v'' mode (''set -o verbose'') | * ''set -v'' mode (''set -o verbose'') | ||
- | * prints commands to be executed to ''stderr'' just like they are read from input (script file or keyboard) | + | * print commands to be executed to ''stderr'' as if they were read from input (script file or keyboard) |
- | * prints everything **before** anything ([[syntax:expansion:intro | substitutions and expansions]], ...) big is applied | + | * print everything **before** any ([[syntax:expansion:intro | substitution and expansion]], ...) is applied |
* ''set -x'' mode (''set -o xtrace'') | * ''set -x'' mode (''set -o xtrace'') | ||
- | * prints everything like it really is executed, after [[syntax:expansion:intro | substitutions and expansions]] applied | + | * print everything as if it were executed, after [[syntax:expansion:intro | substitution and expansion]] is applied |
- | * indicates the depth-level of the subshell (by default by preceeding a ''+'' (plus) sign to the shown command) | + | * indicate the depth-level of the subshell (by default by prefixing a ''+'' (plus) sign to the displayed command) |
- | * indicates the recognized words after [[syntax:expansion:wordsplit | word splitting]] by marking them like ''<nowiki>'x y'</nowiki>'' | + | * indicate the recognized words after [[syntax:expansion:wordsplit | word splitting]] by marking them like ''<nowiki>'x y'</nowiki>'' |
- | * in a 4.1 version of the shell, this debug output can be printed to a configurable file descriptor (by setting the [[syntax:shellvars#BASH_XTRACEFD|BASH_XTRACEFD]] variable) rather than stdout | + | * in shell version 4.1, this debug output can be printed to a configurable file descriptor, rather than sdtout by setting the [[syntax:shellvars#BASH_XTRACEFD|BASH_XTRACEFD]] variable. |
**__Hint:__** These modes can be entered when calling Bash: | **__Hint:__** These modes can be entered when calling Bash: | ||
* from commandline: ''bash -vx ./myscript'' | * from commandline: ''bash -vx ./myscript'' | ||
- | * eventually (OS dependant) from shebang: ''#!/bin/bash -vx'' | + | * from shebang (OS dependant): ''#!/bin/bash -vx'' |
Line 92: | Line 92: | ||
</code> | </code> | ||
- | And now you see that it's ("bar" and "baz") recognized as two separate words (which you also might have realized if you READ THE ERROR MESSAGES ;) ). Let's check it... | + | And now you see that it's ("bar" and "baz") recognized as two separate words (which you would have realized if you READ THE ERROR MESSAGES ;) ). Let's check it... |
<code> | <code> | ||
# next try | # next try | ||
Line 113: | Line 113: | ||
(by AnMaster) | (by AnMaster) | ||
- | ''xtrace'' output would be more useful if it contained source file and line number. Add this somewhere in the beginning of your script to include that information: | + | ''xtrace'' output would be more useful if it contained source file and line number. Add this assignment [[syntax:shellvars#PS4|PS4]] at the beginning of your script to enable the inclusion of that information: |
<code> | <code> | ||
export PS4='+(${BASH_SOURCE}:${LINENO}): ${FUNCNAME[0]:+${FUNCNAME[0]}(): }' | export PS4='+(${BASH_SOURCE}:${LINENO}): ${FUNCNAME[0]:+${FUNCNAME[0]}(): }' | ||
Line 128: | Line 128: | ||
</code> | </code> | ||
- | That helps a lot when the script is long, or when the main script source a lot of other files. | + | That helps a lot when the script is long, or when the main script sources many other files. |
+ | === Set flag variables with descriptive words === | ||
+ | If you test variables that flag the state of options, such as with ''%%if [[ -n $option ]];%%'', consider using descriptive words rather than short codes, such as 0, 1, Y, N, because xtrace will show ''%%[[ -n word ]]%%'' rather than ''%%[[ -n 1 ]]%%'' when the option is set. | ||
===== Debugging commands depending on a set variable ===== | ===== Debugging commands depending on a set variable ===== | ||
For general debugging purposes you can also define a function and a variable to use: | For general debugging purposes you can also define a function and a variable to use: | ||
<code> | <code> | ||
- | DEBUGME() { | + | debugme() { |
- | [[ $SCRIPT_DEBUG = 1 ]] && "$@" || : | + | [[ $script_debug = 1 ]] && "$@" || : |
# be sure to append || : or || true here or use return 0, since the return code | # be sure to append || : or || true here or use return 0, since the return code | ||
# of this function should always be 0 to not influence anything else with an unwanted | # of this function should always be 0 to not influence anything else with an unwanted | ||
Line 144: | Line 145: | ||
</code> | </code> | ||
- | This function does nothing when ''SCRIPT_DEBUG'' is unset or empty, but it executes the given parameters as commands when ''SCRIPT_DEBUG'' is set. Use it like: | + | This function does nothing when ''script_debug'' is unset or empty, but it executes the given parameters as commands when ''script_debug'' is set. Use it like this: |
<code> | <code> | ||
- | SCRIPT_DEBUG=1 | + | script_debug=1 |
- | # to turn off, best do SCRIPT_DEBUG=0 | + | # to turn it off, set script_debug=0 |
- | DEBUGME logger "Sorting the database" | + | debugme logger "Sorting the database" |
database_sort | database_sort | ||
- | DEBUGME logger "Finished sorting the database, exit code $?" | + | debugme logger "Finished sorting the database, exit code $?" |
</code> | </code> | ||
- | Of course this can also be used to just execute something else than echo in case of debugging: | + | Of course this can be used to execute something other than echo during debugging: |
<code> | <code> | ||
- | DEBUGME set -x | + | debugme set -x |
- | some_code | + | # ... some code ... |
- | DEBUGME set +x | + | debugme set +x |
</code> | </code> | ||
===== Dry-run STDIN driven commands ===== | ===== Dry-run STDIN driven commands ===== | ||
- | Imagine you have a script that runs FTP commands for some job using the installed standard FTP client: | + | Imagine you have a script that runs FTP commands using the standard FTP client: |
<code bash> | <code bash> | ||
Line 173: | Line 174: | ||
</code> | </code> | ||
- | A method to dry-run this with debug output is the following: | + | A method to dry-run this with debug output is: |
<code bash> | <code bash> | ||
if [[ $DRY_RUN = yes ]]; then | if [[ $DRY_RUN = yes ]]; then | ||
Line 186: | Line 187: | ||
</code> | </code> | ||
- | This can of course be wrapped in a shell function, for more readable code. | + | This can be wrapped in a shell function for more readable code. |
===== Common error messages ===== | ===== Common error messages ===== | ||
Line 203: | Line 204: | ||
* did you close your ''{'' with a ''}''? | * did you close your ''{'' with a ''}''? | ||
* did you close your ''('' with a '')''? | * did you close your ''('' with a '')''? | ||
- | * ... | ||
- | |||
- | **__Note:__** It seems that here-documents (tested on versions ''1.14.7'', ''2.05b'', ''3.1.17'' and ''4.0'') are correctly terminated when there is an EOF before the end-of-here-document tag (see [[syntax:redirection | redirection]]). The reason is unknown, but it seems to be done on purpose. **UPDATE:** :V4: Bash 4.0 added an extra message for this: ''warning: here-document at line <N> delimited by end-of-file (wanted `<MARKER>')'' | ||
+ | **__Note:__** It seems that here-documents (tested on versions ''1.14.7'', ''2.05b'', ''3.1.17'' and ''4.0'') are correctly terminated when there is an EOF before the end-of-here-document tag (see [[syntax:redirection | redirection]]). The reason is unknown, but it seems to be deliberate. Bash 4.0 added an extra message for this: ''warning: here-document at line <N> delimited by end-of-file (wanted `<MARKER>')'' | ||
Line 220: | Line 219: | ||
</code> | </code> | ||
- | This one simply indicates that the double-quote opened in line 50 does not have a closing partner until the end of file at line 100. | + | This one indicates the double-quote opened in line 50 does not have a matching closing quote. |
- | These //unmatched errors// occour with, for example | + | These //unmatched errors// occur with: |
* double-quote pairs | * double-quote pairs | ||
* single-quote pairs (also ''<nowiki>$'string'</nowiki>''!) | * single-quote pairs (also ''<nowiki>$'string'</nowiki>''!) | ||
- | * missing closing ''}'' with [[syntax:pe | parameter expansion syntax]] | + | * missing a closing ''}'' with [[syntax:pe | parameter expansion syntax]] |
- | * ... | + | |
Line 235: | Line 234: | ||
</code> | </code> | ||
- | You most likely forgot to quote a variable expansion somewhere. See the example for ''xtrace'' output from above. Also external commands may spit out such an error message (though in our example it was the **internal** test-command). | + | You most likely forgot to quote a variable expansion somewhere. See the example for ''xtrace'' output from above. External commands may display such an error message though in our example, it was the **internal** test-command that yielded the error. |
Line 245: | Line 244: | ||
</code> | </code> | ||
- | This is not an error per se. It happens in interactive shells, when the C-Shell-styled history expansion ("''!searchword''") is enabled. This is the default. Disable by: | + | This is not an error per se. It happens in interactive shells, when the C-Shell-styled history expansion ("''!searchword''") is enabled. This is the default. Disable it like this: |
<code> | <code> | ||
set +H | set +H | ||
Line 254: | Line 253: | ||
==== syntax error near unexpected token `(' ==== | ==== syntax error near unexpected token `(' ==== | ||
- | When this happens during a **function definition** in a script or on the commandline, like | + | When this happens during a script **function definition** or on the commandline, e.g. |
<code> | <code> | ||
Line 261: | Line 260: | ||
</code> | </code> | ||
- | ...then you most likely have an alias defined for the name of the function (here: ''foo''). Alias expansion happens before the real language interpretion, thus the alias is expanded and makes your function definition containing invalid syntax. | + | you most likely have an alias defined with the same name as the function (here: ''foo''). Alias expansion happens before the real language interpretion, thus the alias is expanded and makes your function definition invalid. |
===== The CRLF issue ===== | ===== The CRLF issue ===== | ||
Line 272: | Line 271: | ||
* UNIX(r) uses: ''\n'' (ASCII ''LF'' #10) | * UNIX(r) uses: ''\n'' (ASCII ''LF'' #10) | ||
- | Keep in mind that your script file **is a plain text file**, and that the ''CR'' character means nothing special to UNIX(r) - it is treated like any other character. If it's printed to your terminal, a carriage return will effectively place the cursor at the beginning of the //current// line. This can cause much confusion and many headaches, since lines containing CRs are not what they appear to be when printed. In summary, CRs are a pain. | + | Keep in mind your script is a **plain text file**, and the ''CR'' character means nothing special to UNIX(r) - it is treated like any other character. If it's printed to your terminal, a carriage return will effectively place the cursor at the beginning of the //current// line. This can cause much confusion and many headaches, since lines containing CRs are not what they appear to be when printed. In summary, CRs are a pain. |
==== How did a CR end up in my file? ==== | ==== How did a CR end up in my file? ==== | ||
Line 278: | Line 277: | ||
Some possible sources of CRs: | Some possible sources of CRs: | ||
* a DOS/Windows text editor | * a DOS/Windows text editor | ||
- | * a UNIX(r) text editor that is "too smart" when determining the file content type (and says "//ha - it's a DOS text file...//") | + | * a UNIX(r) text editor that is "too smart" when determining the file content type (and thinks "//it's a DOS text file//") |
- | * a direct copy&paste from certain webpages (some pastebins are known to suck) | + | * a direct copy and paste from certain webpages (some pastebins are known for this) |
- | * ... | + | |
==== Why do CRs hurt? ==== | ==== Why do CRs hurt? ==== | ||
Line 293: | Line 292: | ||
Here's what happens because of the ''#!/bin/bash^M'' in our shebang: | Here's what happens because of the ''#!/bin/bash^M'' in our shebang: | ||
- | * the file ''/bin/bash^M'' doesn't exist (hopefully), so ... | + | * the file ''/bin/bash^M'' doesn't exist (hopefully) |
- | * Bash prints an error message which (depending on the terminal, the Bash version, or custom patches!) may or may not expose the problem to you. | + | * So Bash prints an error message which (depending on the terminal, the Bash version, or custom patches!) may or may not expose the problem. |
* the script can't be executed | * the script can't be executed | ||
- | The error message can vary. If you're lucky, you'll get: | + | The error message can vary. If you're lucky, you'll get: |
<code> | <code> | ||
bash: ./testing.sh: /bin/bash^M: bad interpreter: No such file or directory | bash: ./testing.sh: /bin/bash^M: bad interpreter: No such file or directory | ||
</code> | </code> | ||
- | which alerts you of the CR. But you may also get the following: | + | which alerts you to the CR. But you may also get the following: |
<code> | <code> | ||
: bad interpreter: No such file or directory | : bad interpreter: No such file or directory | ||
</code> | </code> | ||
- | Why? Because when printed literally, the ''^M'' makes the cursor go back to the beginning of the line. The whole error message is //printed//, but you //see// only a part of it! | + | Why? Because when printed literally, the ''^M'' makes the cursor go back to the beginning of the line. The whole error message is //printed//, but you //see// only part of it! |
<note warning> | <note warning> | ||
- | You can imagine that this ''^M'' is bad in other places, too. So if you get weird and illogical messages from your script, the chance is high that ''^M'' is envolved. Find and eliminate it! | + | It's easy to imagine the ''^M'' is bad in other places too. If you get weird and illogical messages from your script, rule out the possibility that''^M'' is involved. Find and eliminate it! |
</note> | </note> | ||