| 1 | ---
|
| 2 | default_highlighter: oils-sh
|
| 3 | ---
|
| 4 |
|
| 5 | Tracing Execution in Oils (`xtrace`)
|
| 6 | ===================================
|
| 7 |
|
| 8 | Oils extends shell's `set -x` / `xtrace` mechanism to give you more visibility
|
| 9 | into your program's execution. It shows high-level program structure
|
| 10 | ("functions", `eval`) as well as runtime events (starting and stopping external
|
| 11 | processes).
|
| 12 |
|
| 13 | <div id="toc">
|
| 14 | </div>
|
| 15 |
|
| 16 | ## Background
|
| 17 |
|
| 18 | In shell, the `$PS4` variable controls the prefix of each trace line. The
|
| 19 | default value is `'+ '`, which results in traces like this:
|
| 20 |
|
| 21 | $ sh -x -c 'echo 1; echo 2'
|
| 22 | + echo 1
|
| 23 | 1
|
| 24 | + echo 2
|
| 25 | 2
|
| 26 |
|
| 27 | ### What's Wrong With `set -x`?
|
| 28 |
|
| 29 | - It shows only an `argv` array for commands. It doesn't tell you if the
|
| 30 | command is a builtin, shell function, or external binary, which is important
|
| 31 | for program comprehension (and performance).
|
| 32 | - It doesn't show you which commands are run in **which processes**. Because
|
| 33 | processes have their own state, this is also crucial for understanding a
|
| 34 | shell program. (Example: does `echo x | read` mutate a variable?)
|
| 35 | - It's **missing** other information, like when processes are started and
|
| 36 | stopped, the exit status, and when commands come from `eval` or `source`.
|
| 37 | - Shell **concurrency** makes the trace incomprehensible. For example, partial
|
| 38 | lines can be interleaved.
|
| 39 | - Most implementations don't show non-printable and whitespace characters in a
|
| 40 | coherent way.
|
| 41 |
|
| 42 | <!-- TODO: you generally lose tracing across processes. -->
|
| 43 |
|
| 44 | ## Oils Enhancements
|
| 45 |
|
| 46 | Oils solves these problems. Here's an example of tracing a builtin, a pipeline,
|
| 47 | then another builtin:
|
| 48 |
|
| 49 | $ osh -O ysh:upgrade -x -c 'set +e; ls | grep OOPS | wc -l; echo end'
|
| 50 | . builtin set '+e'
|
| 51 | > pipeline
|
| 52 | | part 103
|
| 53 | . 103 exec ls
|
| 54 | | part 104
|
| 55 | . 104 exec grep OOPS
|
| 56 | | command 105: wc -l
|
| 57 | ; process 103: status 0
|
| 58 | ; process 104: status 1
|
| 59 | ; process 105: status 0
|
| 60 | < pipeline
|
| 61 | . builtin echo end
|
| 62 |
|
| 63 | - Builtins are shown with the `builtin` prefix.
|
| 64 | - External commands are shown with the `command` prefix.
|
| 65 | - Bare `exec()` calls are shown with the `exec` prefix.
|
| 66 | - It shows **synchronous** shell constructs with indentation and the `>`
|
| 67 | and `<` characters. This includes the entire pipeline, as well as `proc`
|
| 68 | calls (not shown).
|
| 69 | - It shows process starts and ends with the `|` and `;` characters. These are
|
| 70 | **asynchronous** in general.
|
| 71 | - It shows the exit status of **every process**, which is important for
|
| 72 | reasoning about failure.
|
| 73 | - It annotates trace lines with the shell PID (when it's not the root PID).
|
| 74 | - Strings in `argv` arrays may be quoted with [QSN]($oils-doc:qsn.html). This
|
| 75 | shows special characters unambiguously, and ensures that each trace entry is
|
| 76 | exactly one physical line.
|
| 77 |
|
| 78 | ### Option Names
|
| 79 |
|
| 80 | This functionality is enabled by the
|
| 81 | [xtrace_rich][] option, but you should
|
| 82 | generally use the `ysh:upgrade` option group. This group turns on
|
| 83 | [xtrace_rich][] and turns off [xtrace_details][], which is equivalent to:
|
| 84 |
|
| 85 | $ shopt --set xtrace_rich
|
| 86 | $ shopt --unset xtrace_details
|
| 87 |
|
| 88 | [xtrace_rich]: ref/chap-option.html#ysh:upgrade
|
| 89 | [xtrace_details]: ref/chap-option.html#ysh:upgrade
|
| 90 |
|
| 91 | ### Variables for the Trace Line
|
| 92 |
|
| 93 | In YSH, the default trace line prefix is:
|
| 94 |
|
| 95 | $ PS4='${SHX_indent}${SHX_punct}${SHX_pid_str} '
|
| 96 |
|
| 97 | - `SHX_indent` is affected by synchronous constructs like `proc` and `eval`, as
|
| 98 | well as new processes.
|
| 99 | - `SHX_pid_str` is only set for child shell processes (to avoid redundancy).
|
| 100 | It has a space at the beginning like `' 123'`.
|
| 101 |
|
| 102 | `SHX_punct` is one of the following:
|
| 103 |
|
| 104 | - `+` for legacy shell tracing ([xtrace_details][])
|
| 105 | - `.` for `builtin` and `exec`
|
| 106 | - `>` and `<` for internal, stack-based, **synchronous** constructs
|
| 107 | - `proc`, `eval`, and `source`, an entire pipeline, and the `wait` builtin
|
| 108 | - running trap handlers (which happens in the main loop)
|
| 109 | - `|` and `;` for process start and wait
|
| 110 | - **synchronous** processes: subshell aka [forkwait][], command sub
|
| 111 | like `$(date)`, simple commands (`;`)
|
| 112 | - **async** processes: [fork][] (`&`), pipeline parts, process subs
|
| 113 | like `<(sort left.txt)`, the process that writes a here doc
|
| 114 |
|
| 115 | [forkwait]: ref/chap-builtin-cmd.html#forkwait
|
| 116 | [fork]: ref/chap-builtin-cmd.html#fork
|
| 117 |
|
| 118 | TODO: Cross-shell tracing
|
| 119 |
|
| 120 | - `SHX_descriptor` is alias for `BASH_XTRACEFD` ?
|
| 121 | - Inherited `$SHX_indent` and `$SHX_pid_str`
|
| 122 |
|
| 123 | ## Other Useful Variables
|
| 124 |
|
| 125 | These variables can enhance the traces.
|
| 126 |
|
| 127 | - `@BASH_SOURCE`, `@BASH_LINENO`, `@FUNCNAME`, `$LINENO`
|
| 128 | - TODO: Add `@SOURCE_NAMES` as alias? `LINE_NUMS`?
|
| 129 | - TODO: `$SECONDS` for timing
|
| 130 |
|
| 131 | <!--
|
| 132 | And OIL_PID? or maybe OIL_CURRENT_PID. or maybe getpid() is better -
|
| 133 | distinguish between functions and values
|
| 134 | -->
|
| 135 |
|
| 136 | ## Parsing `xtrace_rich` Output
|
| 137 |
|
| 138 | TODO
|
| 139 |
|
| 140 | - It's concurrent, but lines are atomically written
|
| 141 | - Specify a regular language?
|
| 142 | - Coalesce by PID?
|
| 143 |
|