janestreet / janestreet/magic-trace

Bug "(event_name cpu-clock)"

Open
#283 3 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
OCaml
Stars
6.3k
Forks
209
PR merge metrics
No merged PRs in 30d

Description

Running
```
./magic-trace run glxinfo64 -- -B
```
I get
```
Intel PT support not found. magic-trace will continue and use sampling instead.
Warning: [-callgraph-mode] is defaulting to [Dwarf] which may have high overhead and decoding time. For more info: https://magic-trace.org/w/b
[ Snapshot taken. ]
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.127 MB /tmp/magic_trace.tmp.72c3de/perf.data (12 samples) ]
[ Finished recording. ]
[ Decoding, this takes a while... ]
Warning: Debug info is unavailable, so filenames and line numbers will not be available in the trace.
See https://github.com/janestreet/magic-trace/wiki/Compiling-code-for-maximum-compatibility-with-magic-trace for more info.
(monitor.ml.Error
("BUG: exception raised while parsing perf output. Please report this to https://github.com/janestreet/magic-trace/issues/"
(exn
("Unexpected event type when parsing perf output" (event_name cpu-clock)))
(perf_output
(" 5488/5488 1539.632720267: 100000 cpu-clock:uH: "
"\t 7fb9b09ba370 [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09bd38c [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09bd4e3 [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09beb7c [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09c332c [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09c46c5 [unknown] (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b09c6b2f XML_ParseBuffer+0x7f (/usr/lib64/libexpat.so.1.8.10)"
"\t 7fb9b0abca85 [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 7fb9b0abe63a [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 7fb9b0ab870a [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 7fb9b0aaceae [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 7fb9b0a9e6e8 [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 7fb9b0a9a4c8 [unknown] (/usr/lib64/libGLX_mesa.so.0.0.0)"
"\t 56458a6b7894 [unknown] ([unknown])"
"\t 7fb9b0c35149 __libc_start_call_main+0x79 (/usr/lib64/libc.so.6)"
"\t 7fb9b0c3520a __libc_start_main@@GLIBC_2.34+0x8a (/usr/lib64/libc.so.6)"
"\t 56458a6b8354 [unknown] ([unknown])")))
("Raised at Base__Error.raise in file \"src/error.ml\" (inlined), line 9, characters 14-30"
"Called from Base__Error.raise_s in file \"src/error.ml\", line 10, characters 19-40"
"Called from Async_kernel__Pipe.map.(fun) in file \"src/pipe.ml\", line 1042, characters 65-70"
"Called from Async_kernel__Job_queue.run_jobs in file \"src/job_queue.ml\", line 167, characters 6-47"
"Caught by monitor Monitor.protect"))
```

This is on
```
uname -a
Linux fedora 6.5.9-300.fc39.x86_64 #1 SMP PREEMPT_DYNAMIC Wed Oct 25 21:39:20 UTC 2023 x86_64 GNU/Linux

perf --version
perf version 6.5.4

cat /proc/cpuinfo
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 141
model name : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
```
which is all Fedora Linux 39 (on VMware Workstation 17.5, running on Windows 11 Professional - which should not matter all that much for the problem I am trying to investigate)

So, this is a bit of a bleeding edge, I guess...

Contributor guide

Open the contributing guide

Research direction

Reproduce the failure with `./magic-trace run glxinfo64 -- -B` and inspect the parser handling the `Unexpected event type when parsing perf output` error. Use the reported `cpu-clock` event and perf output as the case to investigate; done means this valid output no longer causes the trace run to fail.

Written by the indexing model from the issue text.

Assessment

Tech stack
linux, ocaml
Domain
cli, observability, performance
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.