cargo-instruments icon indicating copy to clipboard operation
cargo-instruments copied to clipboard

Instruments can't seem to read the trace files

Open teymour-aldridge opened this issue 4 years ago • 21 comments

I'm trying to profile some code, but whenever I run cargo-instruments I encounter this error:

The document “Launch_simple_agent-0f8bddef344bdebb_2021-07-27_18.16.23_D2914DDE.trace” could not be opened. 
*** -[__NSArrayM insertObject:atIndex:]: object cannot be nil

teymour-aldridge avatar Jul 27 '21 17:07 teymour-aldridge

I'm going to needs macOS/Instruments versions in order to investigate this.

cmyr avatar Jul 28 '21 14:07 cmyr

I'm on MacOS Catalina 10.15.6, using Instruments version 12.4.

teymour-aldridge avatar Aug 02 '21 10:08 teymour-aldridge

Same, though I don't see the nil object error. Trace files just won't open.

Instruments: Version 11.3.1 (11C504) Mac OSX 10.14.6 Mojave cargo-instruments 0.4.1

Running cargo instruments -t time

ckoehler avatar Aug 16 '21 18:08 ckoehler

i'm not able to reproduce on macos 10.15 with instruments 12.4.

my gut instinct here is that it's something like your binary is exiting too quickly, and there's no data generated or something?

I would see if you can generate a valid profile directly using the instruments CLI, like:

instruments -t "Time Profiler" -D out.trace ./target/debug/my_crate ARGS

and see if this produces a trace you can open?

cmyr avatar Aug 16 '21 19:08 cmyr

Yes, that works. I can open that trace.

app_Time-Profiler_2021-08-16T14/03/05.trace -> Are the slashes valid characters in the file name?

ckoehler avatar Aug 16 '21 20:08 ckoehler

good question, where did that file name come from?

cmyr avatar Aug 16 '21 22:08 cmyr

I assumed cargo-instruments generates it...that's the filename in target/instruments when I run cargo instruments -t time. In your example for directly calling instruments, the file is (obviously) out.trace.

ckoehler avatar Aug 16 '21 22:08 ckoehler

interesting, I expect names to be in the format TARGET_Time-Profiler_2021-08-17T09:28:47.trace.

cmyr avatar Aug 17 '21 13:08 cmyr

I think historically colons are also not allowed. OSX sometimes swaps them, according to a brief search. That seems to be what I'm seeing.

ckoehler avatar Aug 17 '21 14:08 ckoehler

interesting, this may be file system dependent? in any case I can patch to remove colons, thanks.

cmyr avatar Aug 17 '21 14:08 cmyr

So it doesn't seem to be colons.

cross-posted from #47:

I'd love to figure out if this is a problem with specific projects, or if it's a problem with your environment, if you have a chance to try cargo instruments on some publicly available code that would be helpful.

If you don't have anything handy, something I just tested was one of the examples in piet:

git checkout https://github.com/linebender/piet.git
cd piet/piet-common
cargo instruments -t time --example=mondrian --features png

does this work for you?

cmyr avatar Aug 17 '21 19:08 cmyr

does this work for you?

That example does work for me.

teymour-aldridge avatar Aug 17 '21 19:08 teymour-aldridge

@teymour-aldridge is the project that is not working for you public?

cmyr avatar Aug 17 '21 19:08 cmyr

Yeah that example works.

❯ cargo instruments -t time --example=mondrian --features png
    Finished dev [unoptimized + debuginfo] target(s) in 0.24s
   Profiling target/debug/examples/mondrian with template 'Time Profiler'
  Trace file target/instruments/mondrian_Time-Profiler_2021-08-17_133758-856.trace

I don't know what kind of app this is. Mine are both services that keep running, so for me, the last thing I see is the "Profiling" line, never the "Trace file" line. Maybe because my apps don't exit. And Instruments never opens.

ckoehler avatar Aug 17 '21 19:08 ckoehler

oh, if your process never exits then instruments is just running forever. You can use the --time-limit argument to kill the process after some elapsed time.

If you want to actually attach to the process while it is running, you're better off doing that through the GUI Instruments.app.

cmyr avatar Aug 17 '21 20:08 cmyr

Yep, which isn't super helpful, so I've been doing just that, running it from the GUI. So everything works as expected for me, then!

ckoehler avatar Aug 17 '21 20:08 ckoehler

@teymour-aldridge Is your application also something that never terminates, or do you think you have a different problem?

cmyr avatar Aug 22 '21 15:08 cmyr

In my case, the time template works, but the alloc template fails.

Here's the program:

use std::collections::BTreeSet;

fn main() {
    let mut s = BTreeSet::new();
    for i in 0..1000 {
        s.insert(i);
    }
}

The command:

cargo instruments -t alloc

Produces these errors:

Screen Shot 2021-09-30 at 2 26 14 PM Screen Shot 2021-09-30 at 2 26 10 PM

Environment:

% xcode-select --version
xcode-select version 2384.
% cargo-instruments --version              
cargo-instruments 0.4.3

Instruments 13.0 Big Sur 11.6 (20G165)

Thanks!

hartshorne avatar Sep 30 '21 21:09 hartshorne

Hi @hartshorne

In my case, the time template works, but the alloc template fails.

I ran into the same problem. I am using Big Sur 11.6.1 (20G224) but the same Instruments version.

It worked after I manually unzipped the missing file and moved it to the right place. This seems a bug in Instruments. This Stack Overflow answer explains how to do that: https://stackoverflow.com/a/67991957/2239513

tatsuya6502 avatar Oct 30 '21 10:10 tatsuya6502

I don't know if this is helpful for anyone, but I was somewhat surprised to find out that trying to end profiling with CTRL-C (which is how I end most of my rust programs) doesn't seem to kill the instruments helper. I believe this is where the issue was stemming for me, I had to set --time-limit=N and use that to kill my server process rather than use a SIGINT, as I'm used to.

staticfloat avatar Jul 26 '22 20:07 staticfloat

I ran into the same problem. But used shell cargo instruments -t Allocations --example my_example --time-limit 10000 --open to resolved it.

ChurchTao avatar Feb 20 '23 10:02 ChurchTao