Bad file/lines in error (assert/fail/alt check) messages from inline functions

Spans of inlined things currently end up pointing at the start of the crate file. This makes them quite useless and confusing.

Example (adapted from pnkfelix's comments below):

% cat -n /tmp/foo.rs
     1  #[link(name="foo", vers="0.0")];
     2  
     3  #[inline(always)]
     4  pub fn access_inline_always(a: &[int], i: uint) -> int {
     5      info!("foo::access_inline_always");
     6      a[i]
     7  }
     8  
     9  #[inline(never)]
    10  pub fn access_inline_never(a: &[int], i: uint) -> int {
    11      info!("foo::access_inline_never");
    12      a[i]
    13  }
% cat -n /tmp/bar.rs
     1  extern mod foo;
     2  
     3  fn main() {
     4      let arr = [1, 2, 3];
     5      let a_0 = foo::access_inline_never(arr, 0);
     6      let a_1 = foo::access_inline_always(arr, 1);
     7      println(format!("arr[0]: {:?} arr[1]: {:?}", a_0, a_1));
     8      let a_4 = foo::access_inline_always(arr, 4);
     9      println(format!("arr[4]: {:?}", a_4));
    10  }
% rustc --cfg debug --lib /tmp/foo.rs
warning: no debug symbols in executable (-arch x86_64)
% rustc -L/tmp /tmp/bar.rs
warning: no debug symbols in executable (-arch x86_64)
% RUST_LOG=foo /tmp/bar
"foo::access_inline_never"
"foo::access_inline_always"
arr[0]: 1 arr[1]: 2
"foo::access_inline_always"
task '<unnamed>' failed at 'index out of bounds: the len is 3 but the index is 4', /tmp/bar.rs:1

Note that the error message points one to /tmp/bar.rs:1 but it should probably point at the vector access itself at line foo.rs:6

oh yes to do this we have to serialize the codemap info a bit more than we do today (otherwise we cannot interpret the spans)

the span info will be huge though (and the codemap info also significant). May be better to somehow distinguish 'significant' spans on the few items that output span info to the binary, and only write those out (in explicit line/char/file format).

We are already serializing all the spans, we just disregard them on deserialization. However, with the new work that I am doing on the serialization process, it should be fairly trivial to customize this so that we do not serialize spans or serialize them in a special way.

Not critical for 0.6; de-milestoning

#3740 is a prereq for this and is in the backwards compatible milestone. Nominating for production ready.

accepted for production-ready milestone

I don't really understand the issue; how can it be reproduced?

@nikomatsakis

(@nikomatsakis, @marijnh ?)

@cmr

@cmr I'm actually unsure whether this is still broken.

Here is an elaborate attempt to recreate the bug:

% cat -n /tmp/foo.rs
     1  use std::num::Zero;
     2  use std::num::One;
     3  
     4  #[inline(always)]
     5  pub fn add2<I:Integer>(x: I) -> I {
     6      assert!(x >= Zero::zero());
     7      (x + One::one()) + One::one()
     8  }
% cat -n /tmp/bar.rs
     1  extern mod foo;
     2  use foo::*;
     3  
     4  fn main() {
     5      let four = add2(2);
     6      println(fmt!("2+2 == %d", four));
     7      let zero = add2(-2);
     8      println(fmt!("-2+2 == %d", zero));
     9  }
% rustc --lib /tmp/foo.rs && rustc -L/tmp /tmp/bar.rs && /tmp/bar
warning: missing crate link meta `name`, using `foo` as default
warning: missing crate link meta `vers`, using `0.0` as default
warning: no debug symbols in executable (-arch x86_64)
warning: no debug symbols in executable (-arch x86_64)
2+2 == 4
rust: task failed at 'assertion failed: x >= Zero::zero()', /tmp/foo.rs:6
rust: domain main @0x7f965c014c10 root task failed

as you can see, the assertion failure in the call to foo's add2 is indeed printing the correct line number within foo.rs.

(There is an issue that was blocking this that remains unfixed, namely #3740, but that issue was partially fixed, so it may no longer be a blocker for this.)

Still broken afaik.

@nikomatsakis

@nikomatsakis can you elaborate what sort of inlined thing one would need to use in another crate to illustrate the bug? I started with something small (which seemed to work to me) and added more and more stuff to it (in the hopes of exposing the bug) until I ended up with the example I wrote above.

Do I need to incorporate uses of -Z debug-info or something?

I believe your example works because the macro-expander is inserting the filename/line-number information before inlining occurs. I imagine you would see the wrong filename/line-number on an out-of-bounds array access, though.

@cmr

@cmr okay @nikomatsakis is correct. Here is a demo of ... well, a semi-related bug. (I forgot to turn on inlining, but I think we see it here due to the parametric definition. Will switch to something that inlines later.)

% cat /tmp/foo.rs
pub fn access<T:Clone>(a: &[T], i: uint) -> T {
    a[i].clone()
}
% cat /tmp/bar.rs
extern mod foo;
use foo::*;

pub fn main() {
    let arr = [1, 2, 3];
    let a_4 = access(arr, 4);
    println(fmt!("arr[4]: %?", a_4));
}
% rustc --lib /tmp/foo.rs && rustc -L/tmp /tmp/bar.rs && /tmp/bar
warning: missing crate link meta `name`, using `foo` as default
warning: missing crate link meta `vers`, using `0.0` as default
warning: no debug symbols in executable (-arch x86_64)
warning: no debug symbols in executable (-arch x86_64)
rust: task failed at 'index out of bounds: the len is 3 but the index is 4', /tmp/bar.rs:1
rust: domain main @0x7fd1e8814c10 root task failed
%

@cmr

@cmr Here is a better example: It shows how the problem arises in the example @nikomatsakis gave (out of bounds array access), but it also shows another instance of the same problem: the info! directive for the inlined functions ends up being associated with the caller module bar rather than the callee module foo where the function is defined, which leads to weird discrepancies for what settings one needs to use for RUST_LOG in order to observe the info! output:

% cat -n /tmp/foo.rs
     1  #[link(name="foo", vers="0.0")];
     2  
     3  #[inline(always)]
     4  pub fn access_inline_always(a: &[int], i: uint) -> int {
     5      info!("foo::access_inline_always");
     6      a[i]
     7  }
     8  
     9  #[inline(never)]
    10  pub fn access_inline_never(a: &[int], i: uint) -> int {
    11      info!("foo::access_inline_never");
    12      a[i]
    13  }
% cat -n /tmp/bar.rs
     1  extern mod foo;
     2  
     3  fn main() {
     4      let arr = [1, 2, 3];
     5      let a_0 = foo::access_inline_never(arr, 0);
     6      let a_1 = foo::access_inline_always(arr, 1);
     7      println(fmt!("arr[0]: %? arr[1]: %?", a_0, a_1));
     8      let a_4 = foo::access_inline_always(arr, 4);
     9      println(fmt!("arr[4]: %?", a_4));
    10  }
% rustc --cfg debug --lib /tmp/foo.rs && rustc -L/tmp /tmp/bar.rs && RUST_LOG=foo=4 /tmp/bar
warning: no debug symbols in executable (-arch x86_64)
warning: no debug symbols in executable (-arch x86_64)
rust: ~"\"foo::access_inline_never\""
arr[0]: 1 arr[1]: 2
rust: task failed at 'index out of bounds: the len is 3 but the index is 4', /tmp/bar.rs:1
rust: domain main @0x7ff333807810 root task failed
% rustc --cfg debug --lib /tmp/foo.rs && rustc -L/tmp /tmp/bar.rs && RUST_LOG=bar=4 /tmp/bar
warning: no debug symbols in executable (-arch x86_64)
warning: no debug symbols in executable (-arch x86_64)
rust: ~"\"foo::access_inline_always\""
arr[0]: 1 arr[1]: 2
rust: ~"\"foo::access_inline_always\""
rust: task failed at 'index out of bounds: the len is 3 but the index is 4', /tmp/bar.rs:1
rust: domain main @0x7fc1b8807810 root task failed
%

auto merge of #15199 : michaelwoerister/rust/cross-crate-stability, r…

Given that #15199 was merged, I'm giving this a close. Please object if you feel differently 😄

Add some performance instrumentation to our code (rust-lang#1972)

Merge pull request rust-lang#1972 from Urgau/triagebot-remove-no-ment…

Merge rust-lang#1972

Navigation Menu

Repository navigation

Bad file/lines in error (assert/fail/alt check) messages from inline functions #1972

12 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Bad file/lines in error (assert/fail/alt check) messages from inline functions #1972

Description

Activity

nikomatsakis commented on Mar 13, 2012

marijnh commented on Mar 13, 2012

nikomatsakis commented on Mar 13, 2012

pnkfelix commented on Mar 22, 2013

metajack commented on May 9, 2013

graydon commented on May 30, 2013

emberian commented on Jul 23, 2013

emberian commented on Jul 23, 2013

pnkfelix commented on Jul 24, 2013

nikomatsakis commented on Jul 24, 2013

pnkfelix commented on Jul 24, 2013

nikomatsakis commented on Jul 24, 2013

pnkfelix commented on Jul 25, 2013

pnkfelix commented on Jul 25, 2013

12 remaining items

steveklabnik commented on Jan 20, 2015

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions