OILS / doc / xtrace.md View on Github | oilshell.org

137 lines, 105 significant
1---
2default_highlighter: oils-sh
3---
4
5Tracing Execution in Oils (`xtrace`)
6===================================
7
8Oils extends shell's `set -x` / `xtrace` mechanism to give you more visibility
9into your program's execution. It shows high-level program structure
10("functions", `eval`) as well as runtime events (starting and stopping external
11processes).
12
13<div id="toc">
14</div>
15
16## Background
17
18In shell, the `$PS4` variable controls the prefix of each trace line. The
19default 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
46Oils solves these problems. Here's an example of tracing a builtin, a pipeline,
47then 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
80This functionality is enabled by the [xtrace_rich]($oil-help) option, but you
81should generally use the `ysh:upgrade` option group. This group turns on
82[xtrace_rich]($oil-help) and turns off [xtrace_details]($oil-help), which is
83equivalent to:
84
85 $ shopt --set xtrace_rich
86 $ shopt --unset xtrace_details
87
88### Variables for the Trace Line
89
90In YSH, the default trace line prefix is:
91
92 $ PS4='${SHX_indent}${SHX_punct}${SHX_pid_str} '
93
94- `SHX_indent` is affected by synchronous constructs like `proc` and `eval`, as
95 well as new processes.
96- `SHX_pid_str` is only set for child shell processes (to avoid redundancy).
97 It has a space at the beginning like `' 123'`.
98
99`SHX_punct` is one of the following:
100
101- `+` for legacy shell tracing ([xtrace_details]($oil-help))
102- `.` for `builtin` and `exec`
103- `>` and `<` for internal, stack-based, **synchronous** constructs
104 - `proc`, `eval`, and `source`, an entire pipeline, and the `wait` builtin
105 - running trap handlers (which happens in the main loop)
106- `|` and `;` for process start and wait
107 - **synchronous** processes: subshell aka [forkwait]($oil-help), command sub
108 like `$(date)`, simple commands (`;`)
109 - **async** processes: [fork]($oil-help) (`&`), pipeline parts, process subs
110 like `<(sort left.txt)`, the process that writes a here doc
111
112TODO: Cross-shell tracing
113
114- `SHX_descriptor` is alias for `BASH_XTRACEFD` ?
115- Inherited `$SHX_indent` and `$SHX_pid_str`
116
117## Other Useful Variables
118
119These variables can enhance the traces.
120
121- `@BASH_SOURCE`, `@BASH_LINENO`, `@FUNCNAME`, `$LINENO`
122 - TODO: Add `@SOURCE_NAMES` as alias? `LINE_NUMS`?
123- TODO: `$SECONDS` for timing
124
125<!--
126And OIL_PID? or maybe OIL_CURRENT_PID. or maybe getpid() is better -
127distinguish between functions and values
128-->
129
130## Parsing `xtrace_rich` Output
131
132TODO
133
134- It's concurrent, but lines are atomically written
135- Specify a regular language?
136- Coalesce by PID?
137