disksnoop.py errors out

[lorddoskias]

So I've been doing the python developer tutorial and when I tried running disksnoop as per lesson 6 I got the following error:

sudo python /usr/share/bcc/examples/tracing/disksnoop.py 
TIME(s)            T  BYTES    LAT(ms)
Traceback (most recent call last):
  File "/usr/share/bcc/examples/tracing/disksnoop.py", line 55, in <module>
    (bytes_s, bflags_s, us_s) = msg.split()
ValueError: too many values to unpack

After printing out the contents of msg it turns out it looks like that: 00000001: 16384 801 1495. So the extra 0000001 that's coming from bpf_trace_printk breaks disksnoop. If I instead change the msg.split line to:

(ignored, bytes_s, bflags_s, us_s) = msg.split()

Everything works as expected.

I've installed iovisor on Ubuntu 16.04, using the latest HWE kernel : 4.13.0-26-generic #29~16.04.2-Ubuntu

[yonghong-song]

This is due to a kernel patch introduced in 4.13 which outputs symbol address. Just submitted a patch to address this issue. Thanks.

[palmtenor]

Do we want to convert the disksnoop.py script to use Perf Ring Buffer, or we want to leave it this way as example of using printk (since the script is in /example)?

[yonghong-song]

Let us keep it with using printk as an example how to use the API.

[brendangregg]

Yes, I use printk early in the tutorial and then introduce the ring buffer later. Easier to learn that way, so one isn't trying to learn too much at once.

[lorddoskias]

I saw the pull request but instead of bcc actually printing some hex address why does it always print 000001 ?

[yonghong-song]

It is due to the old implementation. The message after find the : is : 0x00000001: 1234..., and then the line[ts_end + 4:] is returned which corresponds to 00000001: 1234....

[yonghong-song]

If you are asking why always 0x1 for the symbol address, I did not trace kernel source deep enough enough to find out. I suspect most likely this is due to that this is from trace_printk. Based on Steve's example, some function tracer symbol address seems reasonable.

[pchaigno]

If you are asking why always 0x1 for the symbol address, I did not trace kernel source deep enough enough to find out.

@lorddoskias The 0x1 value is a fake ip value hardcoded for BPF: http://elixir.free-electrons.com/linux/v4.14.8/source/kernel/trace/bpf_trace.c#L212.

[yonghong-song]

Oh, thanks! Quoting the kernel code:

#define __BPF_TP(...)							\
	__trace_printk(1 /* Fake ip will not be printed. */,		\
		       fmt, ##__VA_ARGS__)

Now, the fake ip does get printed in 4.13 and later, or whatever ip will be printed.