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 |
|