Skip to content

Commit 4dc1c47

Browse files
arielb1arielb1
committed
add debugging guide
1 parent eb23925 commit 4dc1c47

File tree

2 files changed

+299
-0
lines changed

2 files changed

+299
-0
lines changed

‎debugging.md

Lines changed: 297 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,297 @@
1+
---
2+
layout: default
3+
title: Debugging the Compiler
4+
---
5+
6+
# Debugging the compiler
7+
[debugging]: #debugging
8+
9+
Here are a few tips to debug the compiler:
10+
11+
## Getting a backtrace
12+
[getting-a-backtrace]: #getting-a-backtrace
13+
14+
When you have an ICE (panic in the compiler), you can set
15+
`RUST_BACKTRACE=1` to get the stack trace of the `panic!` like in
16+
normal Rust programs. IIRC backtraces **don't work** on Mac and on MinGW,
17+
sorry. If you have trouble or the backtraces are full of `unknown`,
18+
you might want to find some way to use Linux or MSVC on Windows.
19+
20+
In the default configuration, you don't have line numbers enabled, so the backtrace looks like this:
21+
```
22+
stack backtrace:
23+
0: std::sys::imp::backtrace::tracing::imp::unwind_backtrace
24+
1: std::sys_common::backtrace::_print
25+
2: std::panicking::default_hook::{{closure}}
26+
3: std::panicking::default_hook
27+
4: std::panicking::rust_panic_with_hook
28+
5: std::panicking::begin_panic
29+
6: rustc_typeck::check::cast::<impl rustc_typeck::check::FnCtxt<'a, 'gcx, 'tcx>>::pointer_kind
30+
(~~~~ LINES REMOVED BY ME FOR BREVITY ~~~~)
31+
32: rustc_typeck::check_crate
32+
33: <std::thread::local::LocalKey<T>>::with
33+
34: <std::thread::local::LocalKey<T>>::with
34+
35: rustc::ty::context::TyCtxt::create_and_enter
35+
36: rustc_driver::driver::compile_input
36+
37: rustc_driver::run_compiler
37+
```
38+
39+
If you want line numbers for the stack trace, you can enable `debuginfo-lines=true` or `debuginfo=true` in your config.toml and rebuild the compiler. Then the backtrace will look like this:
40+
```
41+
stack backtrace:
42+
(~~~~ LINES REMOVED BY ME FOR BREVITY ~~~~)
43+
6: rustc_typeck::check::cast::<impl rustc_typeck::check::FnCtxt<'a, 'gcx, 'tcx>>::pointer_kind
44+
at /home/user/rust/src/librustc_typeck/check/cast.rs:110
45+
7: rustc_typeck::check::cast::CastCheck::check
46+
at /home/user/rust/src/librustc_typeck/check/cast.rs:572
47+
at /home/user/rust/src/librustc_typeck/check/cast.rs:460
48+
at /home/user/rust/src/librustc_typeck/check/cast.rs:370
49+
(~~~~ LINES REMOVED BY ME FOR BREVITY ~~~~)
50+
33: rustc_driver::driver::compile_input
51+
at /home/user/rust/src/librustc_driver/driver.rs:1010
52+
at /home/user/rust/src/librustc_driver/driver.rs:212
53+
34: rustc_driver::run_compiler
54+
at /home/user/rust/src/librustc_driver/lib.rs:253
55+
```
56+
57+
## Getting a backtrace for errors
58+
[getting-a-backtrace-for-errors]: #getting-a-backtrace-for-errors
59+
60+
If you want to get a backtrace to the point where the compiler emits
61+
an error message, you can pass the `-Z treat-err-as-bug`, which
62+
will make the compiler panic on the first error it sees.
63+
64+
This can also help when debugging `delay_span_bug` calls - it will make
65+
the first `delay_span_bug` call panic, which will give you a useful backtrace.
66+
67+
For example:
68+
```
69+
$ cat error.rs
70+
fn main() {
71+
1 + ();
72+
}
73+
$ ./build/x86_64-unknown-linux-gnu/stage1/bin/rustc error.rs
74+
error[E0277]: the trait bound `{integer}: std::ops::Add<()>` is not satisfied
75+
--> error.rs:2:7
76+
|
77+
2 | 1 + ();
78+
| ^ no implementation for `{integer} + ()`
79+
|
80+
= help: the trait `std::ops::Add<()>` is not implemented for `{integer}`
81+
82+
error: aborting due to previous error
83+
84+
$ # Now, where does the error above come from?
85+
$ RUST_BACKTRACE=1 \
86+
./build/x86_64-unknown-linux-gnu/stage1/bin/rustc \
87+
error.rs \
88+
-Z treat-err-as-bug
89+
```
90+
error[E0277]: the trait bound `{integer}: std::ops::Add<()>` is not satisfied
91+
--> error.rs:2:7
92+
|
93+
2 | 1 + ();
94+
| ^ no implementation for `{integer} + ()`
95+
|
96+
= help: the trait `std::ops::Add<()>` is not implemented for `{integer}`
97+
98+
error: internal compiler error: unexpected panic
99+
100+
note: the compiler unexpectedly panicked. this is a bug.
101+
102+
note: we would appreciate a bug report: https://github.com/rust-lang/rust/blob/master/CONTRIBUTING.md#bug-reports
103+
104+
note: rustc 1.24.0-dev running on x86_64-unknown-linux-gnu
105+
106+
note: run with `RUST_BACKTRACE=1` for a backtrace
107+
108+
thread 'rustc' panicked at 'encountered error with `-Z treat_err_as_bug', /home/user/rust/src/librustc_errors/lib.rs:411:12
109+
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
110+
stack backtrace:
111+
(~~~ IRRELEVANT PART OF BACKTRACE REMOVED BY ME ~~~)
112+
7: rustc::traits::error_reporting::<impl rustc::infer::InferCtxt<'a, 'gcx, 'tcx>>::report_selection_error
113+
at /home/user/rust/src/librustc/traits/error_reporting.rs:823
114+
8: rustc::traits::error_reporting::<impl rustc::infer::InferCtxt<'a, 'gcx, 'tcx>>::report_fulfillment_errors
115+
at /home/user/rust/src/librustc/traits/error_reporting.rs:160
116+
at /home/user/rust/src/librustc/traits/error_reporting.rs:112
117+
9: rustc_typeck::check::FnCtxt::select_obligations_where_possible
118+
at /home/user/rust/src/librustc_typeck/check/mod.rs:2192
119+
(~~~ IRRELEVANT PART OF BACKTRACE REMOVED BY ME ~~~)
120+
36: rustc_driver::run_compiler
121+
at /home/user/rust/src/librustc_driver/lib.rs:253
122+
$ # Cool, now I have a backtrace for the error
123+
```
124+
125+
## Getting logging output
126+
[getting-logging-output]: #getting-logging-output
127+
128+
The compiler has a lot of `debug!` calls, which print out logging information
129+
at many points. These are very useful to at least narrow down the location of
130+
a bug if not to find it entirely, or just to orient yourself to why a compiler
131+
is doing a particular thing.
132+
133+
To see the logs, you need to set the `RUST_LOG` environment variable to
134+
your log filter, e.g. to get the logs for a specific module, you can run the
135+
compiler as `RUST_LOG=module::path rustc my-file.rs`. The Rust logs are
136+
powered by [env-logger], and you can look at the docs linked there to see
137+
the full `RUST_LOG` syntax. All `debug!` output will then appear in
138+
standard error.
139+
140+
Note that unless you use a very strict filter, the logger will emit a *lot*
141+
of output - so it's typically a good idea to pipe standard error to a file
142+
and look at the log output with a text editor.
143+
144+
So to put it together.
145+
```
146+
# This puts the output of all debug calls in `librustc/traits` into
147+
# standard error, which might fill your console backscroll.
148+
$ RUST_LOG=rustc::traits rustc +local my-file.rs
149+
150+
# This puts the output of all debug calls in `librustc/traits` in
151+
# `traits-log`, so you can then see it with a text editor.
152+
$ RUST_LOG=rustc::traits rustc +local my-file.rs 2>traits-log
153+
154+
# Not recommended. This will show the output of all `debug!` calls
155+
# in the Rust compiler, and there are a *lot* of them, so it will be
156+
# hard to find anything.
157+
$ RUST_LOG=debug rustc +local my-file.rs 2>all-log
158+
159+
# This will show the output of all `info!` calls in `rustc_trans`.
160+
#
161+
# There's an `info!` statement in `trans_instance` that outputs
162+
# every function that is translated. This is useful to find out
163+
# which function triggers an LLVM assertion, and this is an `info!`
164+
# log rather than a `debug!` log so it will work on the official
165+
# compilers.
166+
$ RUST_LOG=rustc_trans=info rustc +local my-file.rs
167+
```
168+
169+
While calls to `info!` are included in every build of the compiler,
170+
calls to `debug!` are only included in the program if the
171+
`debug-assertions=yes` is turned on in config.toml (it is
172+
turned off by default), so if you don't see `DEBUG` logs, especially
173+
if you run the compiler with `RUST_LOG=rustc rustc some.rs` and only see
174+
`INFO` logs, make sure that `debug-assertions=yes` is turned on in your
175+
config.toml.
176+
177+
I also think that in some cases just setting it will not trigger a rebuild,
178+
so if you changed it and you already have a compiler built, you might
179+
want to call `x.py clean` to force one.
180+
181+
### Logging etiquette
182+
183+
Because calls to `debug!` are removed by default, in most cases, don't worry
184+
about adding "unnecessary" calls to `debug!` and leaving them in in code
185+
you commit - they won't slow
186+
down the performance of what we ship, and if they helped you pinning down
187+
a bug, they will probably help someone else with a different one.
188+
189+
However, there are still a few concerns that you might care about:
190+
191+
### Expensive operations in logs
192+
193+
A note of caution: the expressions *within* the `debug!` call are run
194+
whenever RUST_LOG is set, even if the filter would exclude the log. This means that if in the module `rustc::foo` you have a statement
195+
196+
```Rust
197+
debug!("{:?}", random_operation(tcx));
198+
```
199+
200+
Then if someone runs a debug `rustc` with `RUST_LOG=rustc::bar`, then `random_operation()` will still run - even while it's output will never be needed!
201+
202+
This means that you should not put anything too expensive or likely
203+
to crash there - that would annoy anyone who wants to use logging for their own module. Note that if `RUST_LOG` is unset (the default), then the code will not run - this means that if your logging code panics, then no-one will know it until someone tries to use logging to find *another* bug.
204+
205+
If you *need* to do an expensive operation in a log, be aware that while log expressions are *evaluated* even if logging is not enabled in your module, they are not *formatted* unless it *is*. This means you can put your expensive/crashy operations inside an `fmt::Debug` impl, and they will not be run unless your log is enabled:
206+
207+
```Rust
208+
use std::fmt;
209+
210+
struct ExpensiveOperationContainer<'a, 'gcx, 'tcx>
211+
where 'tcx: 'gcx, 'a: 'tcx
212+
{
213+
tcx: TyCtxt<'a, 'gcx, 'tcx>
214+
}
215+
216+
impl<'a, 'gcx, 'tcx> fmt::Debug for ExpensiveOperationContainer<'a, 'gcx, 'tcx> {
217+
fn fmt(&self, fmt: &mut fmt::Formatter) -> fmt::Result {
218+
let value = random_operation(tcx);
219+
fmt::Debug::fmt(&value, fmt)
220+
}
221+
}
222+
223+
debug!("{:?}", ExpensiveOperationContainer { tcx });
224+
```
225+
226+
## Formatting Graphviz output (.dot files)
227+
[formatting-graphviz-output]: #formatting-graphviz-output
228+
229+
Some compiler options for debugging specific features yield graphviz graphs - e.g.
230+
the `#[rustc_mir(borrowck_graphviz_postflow="suffix.dot")]` attribute
231+
dumps various borrow-checker dataflow graphs.
232+
233+
These all produce `.dot` files. To view these files, install graphviz (e.g.
234+
`apt-get install graphviz`) and then run the following commands:
235+
236+
```
237+
$ dot -T pdf maybe_init_suffix.dot > maybe_init_suffix.pdf
238+
$ firefox maybe_init_suffix.pdf # Or your favorite pdf viewer
239+
```
240+
241+
## Debugging LLVM
242+
[debugging-llvm]: #debugging-llvm
243+
244+
LLVM is a big project on its own that probably needs to have its own debugging
245+
document (not that I could find one). But here are some tips that are important
246+
in a rustc context:
247+
248+
The official compilers (including nightlies) have LLVM assertions disabled,
249+
which means that LLVM assertion failures can show up as compiler crashes (not
250+
ICEs but "real" crashes) and other sorts of weird behavior. If you are
251+
encountering these, it is a good idea to try using a compiler with LLVM
252+
assertions enabled - either an "alt" nightly or a compiler you build yourself
253+
by setting `[llvm] assertions=true` in your config.toml - and
254+
see whether anything turns up.
255+
256+
The rustc build process builds the LLVM tools into `./build/<host-triple>/llvm/bin`. They can be called directly.
257+
258+
The default rustc compilation pipeline has multiple codegen units, which is hard
259+
to replicate manually and means that LLVM is called multiple times in parallel.
260+
If you can get away with it (i.e. if it doesn't make your bug disappear),
261+
passing `-C codegen-units=1` to rustc will make debugging easier.
262+
263+
If you want to play with the optimization pipeline, you can use the `opt` from
264+
there on the IR rustc emits with `--emit=llvm-ir`. Note
265+
that rustc emits different IR depending on whether `-O` is enabled, even without
266+
LLVM's optimizations, so if you want to play with the IR rustc emits, you should:
267+
```
268+
$ rustc +local my-file.rs --emit=llvm-ir -O -C no-prepopulate-passes \
269+
-C codegen-units=1
270+
$ OPT=./build/$TRIPLE/llvm/bin/opt
271+
$ $OPT -S -O2 < my-file.ll > my
272+
```
273+
274+
If you just want to get the LLVM IR during the LLVM pipeline, to e.g. see which
275+
IR causes an optimization-time assertion to fail, or to see when
276+
LLVM performs a particular optimization, you can pass the rustc flag
277+
`-C llvm-args=-print-after-all`, and possibly add
278+
`-C llvm-args='-filter-print-funcs=EXACT_FUNCTION_NAME` (e.g.
279+
`-C llvm-args='-filter-print-funcs=_ZN11collections3str21_$LT$impl$u20$str$GT$7replace17hbe10ea2e7c809b0bE'`).
280+
281+
That produces a lot of output into standard error, so you'll want to pipe
282+
that to some file. Also, if you are using neither `-filter-print-funcs` nor
283+
`-C codegen-units=1`, then, because the multiple codegen units run in parallel,
284+
the printouts will mix together and you won't be able to read anything.
285+
286+
If you want just the IR for a specific function (say, you want to see
287+
why it causes an assertion or doesn't optimize correctly), you can use
288+
`llvm-extract`, e.g.
289+
```
290+
$ ./build/$TRIPLE/llvm/bin/llvm-extract \
291+
-func='_ZN11collections3str21_$LT$impl$u20$str$GT$7replace17hbe10ea2e7c809b0bE' \
292+
-S \
293+
< unextracted.ll \
294+
> extracted.ll
295+
```
296+
297+
[env-logger]: https://docs.rs/env_logger/0.4.3/env_logger/

‎index.md

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,8 @@ Describes
6464

6565
* [Homu/Bors Syntax](https://buildbot2.rust-lang.org/homu/)
6666

67+
* [Debugging the compiler](debugging.html). Tips for debugging the compiler.
68+
6769
<script>
6870

6971
document.addEventListener("DOMContentLoaded", function() {

0 commit comments

Comments
 (0)