From 1abd1cf43b7b29cc0a46cb2c3b52ca9d7fceea55 Mon Sep 17 00:00:00 2001 From: Eduard-Mihai Burtescu Date: Thu, 20 Jul 2023 20:18:14 +0300 Subject: [PATCH] Show `panic!` messages via `debugPrintf`, even including some runtime arguments (`{u,i,f}32` as `{}` or `{:?}`). --- CHANGELOG.md | 4 + .../src/builder/builder_methods.rs | 146 ++++++++++++++++-- .../src/builder/intrinsics.rs | 16 +- .../src/codegen_cx/constant.rs | 8 +- .../rustc_codegen_spirv/src/custom_insts.rs | 21 ++- .../src/linker/spirt_passes/controlflow.rs | 37 +++-- 6 files changed, 201 insertions(+), 31 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d4c84d5431..f5ed85dc6b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -30,6 +30,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] ### Added ⭐ +- [PR#1082](https://github.com/EmbarkStudios/rust-gpu/pull/1082) added partial + support for extracting `format_args!` from `panic!`s, and converting them to + `debugPrintf` calls (if enabled via `ShaderPanicStrategy`), including runtime + arguments (`u32`/`i32`/`f32` with `Display`/`Debug` formatting, for now) - [PR#1081](https://github.com/EmbarkStudios/rust-gpu/pull/1081) added the ability to access SPIR-V specialization constants (`OpSpecConstant`) via entry-point inputs declared as `#[spirv(spec_constant(id = ..., default = ...))] x: u32` diff --git a/crates/rustc_codegen_spirv/src/builder/builder_methods.rs b/crates/rustc_codegen_spirv/src/builder/builder_methods.rs index 80415b1a67..ef92f02da3 100644 --- a/crates/rustc_codegen_spirv/src/builder/builder_methods.rs +++ b/crates/rustc_codegen_spirv/src/builder/builder_methods.rs @@ -20,11 +20,13 @@ use rustc_codegen_ssa::MemFlags; use rustc_data_structures::fx::FxHashSet; use rustc_middle::bug; use rustc_middle::middle::codegen_fn_attrs::CodegenFnAttrs; +use rustc_middle::ty::layout::LayoutOf; use rustc_middle::ty::Ty; use rustc_span::Span; use rustc_target::abi::call::FnAbi; use rustc_target::abi::{Abi, Align, Scalar, Size, WrappingRange}; use smallvec::SmallVec; +use std::borrow::Cow; use std::cell::Cell; use std::convert::TryInto; use std::iter::{self, empty}; @@ -2414,12 +2416,25 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { // nor simplified in MIR (e.g. promoted to a constant) in any way, // so we have to try and remove the `fmt::Arguments::new` call here. #[derive(Default)] - struct DecodedFormatArgs {} + struct DecodedFormatArgs<'tcx> { + /// If fully constant, the `pieces: &'a [&'static str]` input + /// of `fmt::Arguments<'a>` (i.e. the strings between args). + const_pieces: Option>, + + /// Original references for `fmt::Arguments<'a>` dynamic arguments, + /// i.e. the `&'a T` passed to `fmt::rt::Argument::<'a>::new_*`, + /// tracking the type `T` and `char` formatting specifier. + /// + /// E.g. for `format_args!("{a} {b:x}")` they'll be: + /// * `&a` with `typeof a` and ' ', + /// *`&b` with `typeof b` and 'x' + ref_arg_ids_with_ty_and_spec: SmallVec<[(Word, Ty<'tcx>, char); 2]>, + } struct FormatArgsNotRecognized(String); // HACK(eddyb) this is basically a `try` block. let try_decode_and_remove_format_args = || { - let decoded_format_args = DecodedFormatArgs::default(); + let mut decoded_format_args = DecodedFormatArgs::default(); let const_u32_as_usize = |ct_id| match self.builder.lookup_const_by_id(ct_id)? { SpirvConst::U32(x) => Some(x as usize), @@ -2441,6 +2456,32 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { } None }; + let const_str_as_utf8 = |str_ptr_and_len_ids: &[Word]| { + let piece_str_bytes = const_slice_as_elem_ids(str_ptr_and_len_ids)? + .iter() + .map(|&id| u8::try_from(const_u32_as_usize(id)?).ok()) + .collect::>>()?; + String::from_utf8(piece_str_bytes).ok() + }; + + // HACK(eddyb) some entry-points only take a `&str`, not `fmt::Arguments`. + if let [ + SpirvValue { + kind: SpirvValueKind::Def(a_id), + .. + }, + SpirvValue { + kind: SpirvValueKind::Def(b_id), + .. + }, + _, // `&'static panic::Location<'static>` + ] = args[..] + { + if let Some(const_msg) = const_str_as_utf8(&[a_id, b_id]) { + decoded_format_args.const_pieces = Some([const_msg].into_iter().collect()); + return Ok(decoded_format_args); + } + } let format_args_id = match args { &[ @@ -2503,6 +2544,7 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { #[derive(Debug)] enum Inst<'tcx, ID> { Bitcast(ID, ID), + CompositeExtract(ID, ID, u32), AccessChain(ID, ID, SpirvConst<'tcx>), InBoundsAccessChain(ID, ID, SpirvConst<'tcx>), Store(ID, ID), @@ -2519,6 +2561,15 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { let (i, inst) = non_debug_insts.next_back()?; taken_inst_idx_range.start.set(i); + // HACK(eddyb) avoid the logic below that assumes only ID operands + if inst.class.opcode == Op::CompositeExtract { + if let (Some(r), &[Operand::IdRef(x), Operand::LiteralInt32(i)]) = + (inst.result_id, &inst.operands[..]) + { + return Some(Inst::CompositeExtract(r, x, i)); + } + } + // HACK(eddyb) all instructions accepted below // are expected to take no more than 4 operands, // and this is easier to use than an iterator. @@ -2716,6 +2767,26 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { } } + // If the `pieces: &[&str]` slice needs a bitcast, it'll be here. + let pieces_slice_ptr_id = match try_rev_take(1).as_deref() { + Some(&[Inst::Bitcast(out_id, in_id)]) if out_id == pieces_slice_ptr_id => in_id, + _ => pieces_slice_ptr_id, + }; + decoded_format_args.const_pieces = + const_slice_as_elem_ids(&[pieces_slice_ptr_id, pieces_len_id]).and_then( + |piece_ids| { + piece_ids + .iter() + .map(|&piece_id| { + match self.builder.lookup_const_by_id(piece_id)? { + SpirvConst::Composite(piece) => const_str_as_utf8(piece), + _ => None, + } + }) + .collect::>() + }, + ); + // Keep all instructions up to (but not including) the last one // confirmed above to be the first instruction of `format_args!`. func.blocks[block_idx] @@ -2725,8 +2796,61 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { Ok(decoded_format_args) }; - match try_decode_and_remove_format_args() { - Ok(DecodedFormatArgs {}) => {} + let mut debug_printf_args = SmallVec::<[_; 2]>::new(); + let message = match try_decode_and_remove_format_args() { + Ok(DecodedFormatArgs { + const_pieces, + ref_arg_ids_with_ty_and_spec, + }) => { + match const_pieces { + Some(const_pieces) => { + const_pieces + .into_iter() + .map(|s| Cow::Owned(s.replace('%', "%%"))) + .interleave(ref_arg_ids_with_ty_and_spec.iter().map( + |&(ref_id, ty, spec)| { + use rustc_target::abi::{Integer::*, Primitive::*}; + + let layout = self.layout_of(ty); + + let scalar = match layout.abi { + Abi::Scalar(scalar) => Some(scalar.primitive()), + _ => None, + }; + let debug_printf_fmt = match (spec, scalar) { + // FIXME(eddyb) support more of these, + // potentially recursing to print ADTs. + (' ' | '?', Some(Int(I32, false))) => "%u", + ('x', Some(Int(I32, false))) => "%x", + (' ' | '?', Some(Int(I32, true))) => "%i", + (' ' | '?', Some(F32)) => "%f", + + _ => "", + }; + + if debug_printf_fmt.is_empty() { + return Cow::Owned( + format!("{{/* unprintable {ty} */:{spec}}}") + .replace('%', "%%"), + ); + } + + let spirv_type = layout.spirv_type(self.span(), self); + debug_printf_args.push( + self.emit() + .load(spirv_type, None, ref_id, None, []) + .unwrap() + .with_type(spirv_type), + ); + Cow::Borrowed(debug_printf_fmt) + }, + )) + .collect::() + } + None => "".into(), + } + } + Err(FormatArgsNotRecognized(step)) => { if let Some(current_span) = self.current_span { let mut warn = self.tcx.sess.struct_span_warn( @@ -2738,8 +2862,8 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { "compilation may later fail due to leftover `format_args!` internals", ); - if self.tcx.sess.opts.unstable_opts.inline_mir != Some(true) { - warn.note("missing `-Zinline-mir=on` flag (should've been set by `spirv-builder`)") + if self.tcx.sess.opts.unstable_opts.inline_mir != Some(false) { + warn.note("missing `-Zinline-mir=off` flag (should've been set by `spirv-builder`)") .help("check `.cargo` and environment variables for potential overrides") .help("(or, if not using `spirv-builder` at all, add the flag manually)"); } else { @@ -2748,13 +2872,17 @@ impl<'a, 'tcx> BuilderMethods<'a, 'tcx> for Builder<'a, 'tcx> { warn.emit(); } + " (failed to find/decode `format_args!` expansion)".into() } - } + }; // HACK(eddyb) redirect any possible panic call to an abort, to avoid // needing to materialize `&core::panic::Location` or `format_args!`. - // FIXME(eddyb) find a way to extract the original message. - self.abort_with_message("panicked: ".into()); + self.abort_with_message_and_debug_printf_args( + // HACK(eddyb) `|` is an ad-hoc convention of `linker::spirt_passes::controlflow`. + format!("panicked|{message}"), + debug_printf_args, + ); self.undef(result_type) } else if let Some(mode) = buffer_load_intrinsic { self.codegen_buffer_load_intrinsic(result_type, args, mode) diff --git a/crates/rustc_codegen_spirv/src/builder/intrinsics.rs b/crates/rustc_codegen_spirv/src/builder/intrinsics.rs index b94475c5dc..982e47f13d 100644 --- a/crates/rustc_codegen_spirv/src/builder/intrinsics.rs +++ b/crates/rustc_codegen_spirv/src/builder/intrinsics.rs @@ -339,7 +339,11 @@ impl<'a, 'tcx> IntrinsicCallMethods<'tcx> for Builder<'a, 'tcx> { } fn abort(&mut self) { - self.abort_with_message("aborted: intrinsics::abort() called".into()); + // HACK(eddyb) `|` is an ad-hoc convention of `linker::spirt_passes::controlflow`. + self.abort_with_message_and_debug_printf_args( + "aborted|intrinsics::abort() called".into(), + [], + ); } fn assume(&mut self, _val: Self::Value) { @@ -374,7 +378,11 @@ impl<'a, 'tcx> IntrinsicCallMethods<'tcx> for Builder<'a, 'tcx> { } impl Builder<'_, '_> { - pub fn abort_with_message(&mut self, message: String) { + pub fn abort_with_message_and_debug_printf_args( + &mut self, + message: String, + debug_printf_args: impl IntoIterator, + ) { // FIXME(eddyb) this should be cached more efficiently. let void_ty = SpirvType::Void.def(rustc_span::DUMMY_SP, self); @@ -385,6 +393,10 @@ impl Builder<'_, '_> { void_ty, CustomInst::Abort { message: Operand::IdRef(message_id), + debug_printf_args: debug_printf_args + .into_iter() + .map(|arg| Operand::IdRef(arg.def(self))) + .collect(), }, ); self.unreachable(); diff --git a/crates/rustc_codegen_spirv/src/codegen_cx/constant.rs b/crates/rustc_codegen_spirv/src/codegen_cx/constant.rs index 4f53fab9bc..65fe219e00 100644 --- a/crates/rustc_codegen_spirv/src/codegen_cx/constant.rs +++ b/crates/rustc_codegen_spirv/src/codegen_cx/constant.rs @@ -172,12 +172,16 @@ impl<'tcx> ConstMethods<'tcx> for CodegenCx<'tcx> { let str_ty = self .layout_of(self.tcx.types.str_) .spirv_type(DUMMY_SP, self); - // FIXME(eddyb) include the actual byte data. ( self.def_constant( self.type_ptr_to(str_ty), SpirvConst::PtrTo { - pointee: self.undef(str_ty).def_cx(self), + pointee: self + .constant_composite( + str_ty, + s.bytes().map(|b| self.const_u8(b).def_cx(self)), + ) + .def_cx(self), }, ), self.const_usize(len as u64), diff --git a/crates/rustc_codegen_spirv/src/custom_insts.rs b/crates/rustc_codegen_spirv/src/custom_insts.rs index 4242d5802d..4ec02c5baa 100644 --- a/crates/rustc_codegen_spirv/src/custom_insts.rs +++ b/crates/rustc_codegen_spirv/src/custom_insts.rs @@ -49,9 +49,9 @@ lazy_static! { } macro_rules! def_custom_insts { - ($($num:literal => $name:ident $({ $($field:ident),+ $(,)? })?),+ $(,)?) => { + ($($num:literal => $name:ident $({ $($field:ident),+ $(, ..$variadic_field:ident)? $(,)? })?),+ $(,)?) => { const SCHEMA: &[(u32, &str, &[&str])] = &[ - $(($num, stringify!($name), &[$($(stringify!($field)),+)?])),+ + $(($num, stringify!($name), &[$($(stringify!($field),)+ $(stringify!(..$variadic_field),)?)?])),+ ]; #[repr(u32)] @@ -74,16 +74,19 @@ macro_rules! def_custom_insts { pub fn with_operands(self, operands: &[T]) -> CustomInst { match self { $(Self::$name => match operands { - [$($($field),+)?] => CustomInst::$name $({ $($field: $field.clone()),+ })?, + [$($($field,)+ $(ref $variadic_field @ ..)?)?] => CustomInst::$name $({ + $($field: $field.clone(),)+ + $($variadic_field: $variadic_field.iter().cloned().collect())? + })?, _ => unreachable!("{self:?} does not have the right number of operands"), }),+ } } } - #[derive(Copy, Clone, Debug)] + #[derive(Clone, Debug)] pub enum CustomInst { - $($name $({ $($field: T),+ })?),+ + $($name $({ $($field: T,)+ $($variadic_field: SmallVec<[T; 4]>)? })?),+ } impl CustomInst { @@ -96,7 +99,9 @@ macro_rules! def_custom_insts { // HACK(eddyb) this should return an iterator, but that's too much effort. pub fn into_operands(self) -> SmallVec<[T; 8]> { match self { - $(Self::$name $({ $($field),+ })? => [$($($field),+)?].into_iter().collect()),+ + $(Self::$name $({ $($field,)+ $($variadic_field)? })? => { + [$($($field),+)?].into_iter() $($(.chain($variadic_field))?)? .collect() + })+ } } } @@ -146,7 +151,9 @@ def_custom_insts! { // users to do `catch_unwind` at the top-level of their shader to handle // panics specially (e.g. by appending to a custom buffer, or using some // specific color in a fragment shader, to indicate a panic happened). - 4 => Abort { message }, + // NOTE(eddyb) the `message` string follows `debugPrintf` rules, with remaining + // operands (collected into `debug_printf_args`) being its formatting arguments. + 4 => Abort { message, ..debug_printf_args }, } impl CustomOp { diff --git a/crates/rustc_codegen_spirv/src/linker/spirt_passes/controlflow.rs b/crates/rustc_codegen_spirv/src/linker/spirt_passes/controlflow.rs index e22c94beab..21e263052a 100644 --- a/crates/rustc_codegen_spirv/src/linker/spirt_passes/controlflow.rs +++ b/crates/rustc_codegen_spirv/src/linker/spirt_passes/controlflow.rs @@ -240,8 +240,13 @@ pub fn convert_custom_aborts_to_unstructured_returns_in_entry_points( .map(|(func_at_inst, custom)| (func_at_inst, custom.unwrap())) .find(|(_, custom)| !custom.op().is_debuginfo()) .filter(|(_, custom)| custom.op().is_terminator()); - if let Some((func_at_abort_inst, CustomInst::Abort { message })) = - custom_terminator_inst + if let Some(( + func_at_abort_inst, + CustomInst::Abort { + message, + debug_printf_args: message_debug_printf_args, + }, + )) = custom_terminator_inst { let abort_inst = func_at_abort_inst.position; terminator.kind = cfg::ControlInstKind::Return; @@ -332,29 +337,38 @@ pub fn convert_custom_aborts_to_unstructured_returns_in_entry_points( // HACK(eddyb) this improves readability w/ very verbose Vulkan loggers. fmt += "\n"; - fmt += "[RUST-GPU] "; - fmt += &cx[const_str(message)].replace('%', "%%"); + fmt += "["; + + // NB: `message` has its own `message_debug_printf_args` + // it formats, and as such any escaping is already done. + let message = &cx[const_str(message)]; + let (message_kind, message) = + message.split_once('|').unwrap_or(("", message)); - // FIXME(eddyb) deduplicate with "called at" form below - // (not trivial becasue both closures would borrow `fmt`). if let Some((file, line, col)) = current_debug_src_loc.take() { - fmt += &format!("\n at {file}:{line}:{col}").replace('%', "%%"); + fmt += &format!("Rust {message_kind} at {file}:{line}:{col}") + .replace('%', "%%"); + } else { + fmt += message_kind; } + fmt += "]\n "; + fmt += &message.replace('\n', "\n "); + let mut innermost = true; let mut append_call = |callsite_debug_src_loc, callee: &str| { if innermost { innermost = false; - fmt += "\n in "; + fmt += "\n in "; } else if current_debug_src_loc.is_some() { - fmt += "\n by "; + fmt += "\n by "; } else { // HACK(eddyb) previous call didn't have a `called at` line. - fmt += "\n called by "; + fmt += "\n called by "; } fmt += callee; if let Some((file, line, col)) = callsite_debug_src_loc { - fmt += &format!("\n called at {file}:{line}:{col}") + fmt += &format!("\n called at {file}:{line}:{col}") .replace('%', "%%"); } current_debug_src_loc = callsite_debug_src_loc; @@ -373,6 +387,7 @@ pub fn convert_custom_aborts_to_unstructured_returns_in_entry_points( }; abort_inst_def.inputs = [Value::Const(mk_const_str(cx.intern(fmt)))] .into_iter() + .chain(message_debug_printf_args) .chain(debug_printf_context_inputs.iter().copied()) .collect();