Fancy progress bar mixes with warnings

[RalfJung]

I just saw the following when compiling rustc:

warning: unused imports: `PointerArithmetic`, `Scalar`==========>    ] 102/110: rustc_mir                                                                                                                          
  --> librustc_mir/interpret/validity.rs:18:5
   |
18 |     Scalar, AllocType, EvalResult, EvalErrorKind, PointerArithmetic
   |     ^^^^^^                                        ^^^^^^^^^^^^^^^^^
   |
   = note: #[warn(unused_imports)] on by default

There still seem to be problems with mixing output.

This is using gnome-terminal on Debian testing.

[alexcrichton]

Do you know what version of Cargo was being used?

[RalfJung]

Uh, current bootstrap? The base commit is rust-lang/rust@2d1065b.

[alexcrichton]

Ok, that's the tip of the rust-1.30.0 branch which has all the relevant fixes we implemented for this feature. @kennytm do you have thoughts on what might be causing this?

[kennytm]

Reproduced with both the bootstrap and latest cargo. I suspect rustbuild is interfering with the output.

[RalfJung]

This gets even worse when one looks at a rustc ICE:

thread 'main' panicked at 'called `Option::unwrap()` on a `None` value', libcore/option.rs:355:21rustc-demangle, fmt_macros, rustc_fs_util, rustc-serialize, quick-error, rustc_platform_intrinsics, crossbeam...  
   Compiling log v0.4.5                                                                                                                                                                                            
   Compiling arrayvec v0.4.7                                                                                                                                                                                       
   Compiling unreachable v1.0.0                                                                                                                                                                                    
stack backtrace:============>                                         ] 30/110: rustc(build.rs), rustc-demangle, fmt_macros, rustc-serialize, rustc_platform_intrinsics, log, arrayvec, unreachable                
   0: std::sys::unix::backtrace::tracing::imp::unwind_backtrace
             at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1: std::sys_common::backtrace::print
             at libstd/sys_common/backtrace.rs:71
             at libstd/sys_common/backtrace.rs:59
   2: std::panicking::default_hook::{{closure}}
             at libstd/panicking.rs:211
   3: std::panicking::default_hook
             at libstd/panicking.rs:227
   4: rustc::util::common::panic_hook
             at librustc/util/common.rs:51
   5: std::panicking::rust_panic_with_hook
             at libstd/panicking.rs:480
   6: std::panicking::continue_panic_fmt
             at libstd/panicking.rs:390
   7: rust_begin_unwind
             at libstd/panicking.rs:325
   8: core::panicking::panic_fmt
             at libcore/panicking.rs:77
   9: core::panicking::panic
             at libcore/panicking.rs:52
  10: rustc_typeck::check::wfcheck::check_impl_item
             at ./libcore/macros.rs:20
             at librustc_typeck/check/wfcheck.rs:172
  11: rustc::ty::query::<impl rustc::ty::query::config::QueryAccessors<'tcx> for rustc::ty::query::queries::check_impl_item_well_formed<'tcx>>::compute
   Compiling rustc-rayon-core v0.1.1                                                                                                                                                                               
             at librustc/ty/query/plumbing.rs:826                     ] 31/110: rustc(build.rs), rustc-demangle, fmt_macros, rustc-serialize, rustc_platform_intrinsics, log, arrayvec, rustc-rayon-core(build)    
  12: rustc::ty::context::tls::with_context
             at librustc/dep_graph/graph.rs:275
             at librustc/ty/context.rs:2036
             at librustc/ty/context.rs:1975
             at librustc/ty/context.rs:2035
             at librustc/dep_graph/graph.rs:274
             at librustc/ty/context.rs:2120
             at librustc/ty/context.rs:2111
             at librustc/ty/context.rs:2120
  13: rustc::dep_graph::graph::DepGraph::with_task_impl
   Compiling owning_ref v0.3.3                                                                                                                                                                                     
             at librustc/dep_graph/graph.rs:268                       ] 32/110: rustc(build.rs), rustc-demangle, fmt_macros, rustc-serialize, rustc_platform_intrinsics, log, arrayvec, owning_ref                 
  14: rustc::ty::context::tls::with_related_context
             at librustc/dep_graph/graph.rs:208
             at librustc/ty/query/plumbing.rs:550
             at librustc/ty/query/plumbing.rs:208
             at librustc/ty/context.rs:2036
             at librustc/ty/context.rs:1975
             at librustc/ty/context.rs:2035
             at librustc/ty/query/plumbing.rs:207
             at librustc/ty/context.rs:2136
             at librustc/ty/context.rs:2120
             at librustc/ty/context.rs:2111
             at librustc/ty/context.rs:2120
             at librustc/ty/context.rs:2131
  15: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt<'a, 'gcx, 'tcx>>::force_query_with_job
   Compiling rand v0.5.5                                                                                                                                                                                           
             at librustc/ty/query/plumbing.rs:197                     ] 33/110: rustc(build.rs), rustc-demangle, fmt_macros, rustc-serialize, rustc_platform_intrinsics, arrayvec, owning_ref, rand                
             at librustc/ty/query/plumbing.rs:543
  16: rustc::ty::query::plumbing::<impl rustc::ty::context::TyCtxt<'a, 'gcx, 'tcx>>::force_query
             at librustc/ty/query/plumbing.rs:621

[alexcrichton]

This is a rustbuild-specific issue but one that I think is fixable in Cargo as well. This also explains why no other project other than rustc is running into this. Rustbuild by default passes --message-format=json to Cargo but then fools rustc back into not producing json diagnostics. This tricks Cargo, however, when it attempts to reroute output.

Cargo takes a different path when executing rustc with json messages, and the line handler does a direct writeln! which isn't synchronized with the progress bar on the main thread. This needs to be updated to do something like this by sending messages to print back to the main thread which can coordinate with printing the progress bar.

[dwijnand]

Is rustbuild still affected by this, does anyone know?

[dwijnand]

See also #6615

[ehuss]

I'm pretty sure this has since been fixed, especially now that rustc's bootstrap always uses json.