Bcc: With latest commits it's imposible to trace more than 200 syscalls.

[vitalyvch]

The root of issue still is in an investigation, but if you have some ideas I would like to know them.

error from libbcc:

mmap: cannot allocate memory

@marcinslusarz, @GBuella, @ldorau, @plebioda, @sarahjelinek

[brendangregg]

If you need to trace all the syscalls, then have you looked at the raw_syscalls:sys_enter, raw_syscalls:sys_exit tracepoints? 2 tracepoints to cover them all. I normally avoid them because I want to trace individual syscalls.

[vitalyvch]

Yes, I tried them. Kernels, which are actual for us, reject attaching of eBPF to that tracepoints for this reason: #748

So I use solution mentioned at the end of that thread.

[goldshtn]

I bisected and it looks like this was broken by b77915df95b971557dcb42606f493ffb5175a8ec -- this is the PR by @derek0883 that introduced support for concurrent probe users. Can you please take a look?

/cc @4ast @brendangregg

[goldshtn]

To reproduce: funccount 'SyS_*' -- works before this commit, dies on this commit (probably due to out of memory but not sure).

[vitalyvch]

From my point of view, the most suspicious changes were introduced into src/cc/libbpf.c, function "bpf_attach_kprobe()", lines 375-386.

[derek0883]

Thank you guys.
Just did a quick testing.
My commit b77915d
will mkdir under /sys/kernel/debug/instances directory for each attach function.
funccount 'SyS_*' will try to attach about 200 function, in current implementation, this will call instance_mkdir in kernel/trace/trace.c,

#define TRACE_BUF_SIZE_DEFAULT  1441792UL /* 16384 * 88 (sizeof(entry)) */
static unsigned long        trace_buf_size = TRACE_BUF_SIZE_DEFAULT;

static int instance_mkdir(const char *name)
{
if (allocate_trace_buffers(tr, trace_buf_size) < 0)
}

This will trigger out of memory, then will be killed. you can get following error from dmesg or syslog.

Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087380] funccount.py invoked oom-killer: gfp_mask=0x240c0c0, order=2, oom_score_adj=0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087383] funccount.py cpuset=/ mems_allowed=0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087387] CPU: 2 PID: 30944 Comm: funccount.py Tainted: G        W  OE   4.4.0-59-generic #80-Ubuntu
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087389] Hardware name: LENOVO 2342CTO/2342CTO, BIOS G1ET73WW (2.09 ) 10/19/2012
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087390]  0000000000000286 00000000d27459aa ffff88015f183b00 ffffffff813f7583
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087392]  ffff88015f183cd8 ffff88000f4d8e00 ffff88015f183b70 ffffffff8120ad5e
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087393]  0000000000000015 0000000000000000 ffff8800142fc9c0 ffff8801c4d9e200
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087395] Call Trace:
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087399]  [<ffffffff813f7583>] dump_stack+0x63/0x90
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087402]  [<ffffffff8120ad5e>] dump_header+0x5a/0x1c5
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087405]  [<ffffffff81390584>] ? apparmor_capable+0xc4/0x1b0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087407]  [<ffffffff81192722>] oom_kill_process+0x202/0x3c0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087409]  [<ffffffff81192b49>] out_of_memory+0x219/0x460
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087411]  [<ffffffff81198abd>] __alloc_pages_slowpath.constprop.88+0x8fd/0xa70
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087413]  [<ffffffff81198eb6>] __alloc_pages_nodemask+0x286/0x2a0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087416]  [<ffffffff811e271c>] alloc_pages_current+0x8c/0x110
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087417]  [<ffffffff81196b49>] alloc_kmem_pages+0x19/0x90
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087419]  [<ffffffff811b449e>] kmalloc_order_trace+0x2e/0xe0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087423]  [<ffffffff81328c92>] ? get_dname.isra.6+0x22/0x50
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087425]  [<ffffffff8115438f>] instance_mkdir+0x5f/0x240
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087427]  [<ffffffff81328d90>] tracefs_syscall_mkdir+0x40/0x70
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087430]  [<ffffffff8121b77c>] vfs_mkdir+0x10c/0x1b0
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087431]  [<ffffffff8121fc80>] SyS_mkdir+0xd0/0x100
Feb  5 13:54:13 ThinkPad-T430 kernel: [667147.087434]  [<ffffffff818384f2>] entry_SYSCALL_64_fastpath+0x16/0x71

How ever, seems current kernel implementation must make dir for each attached instance. e.g.
try to use bcc_pid as instance. 2nd one will get "Device or resource busy"
write: p:kprobes/bcc_7880 SyS_chown
write: p:kprobes/bcc_7880 SyS_old_getrlimit

Will update if I can get more information or solution for this.

[goldshtn]

If this can't be solved I propose we revert the patch, or at least provide a way to not use it when attaching probes - this blocks useful functionality.

[4ast]

right. each tracing instance is ~20Mbyte of kernel memory, so no wonder it runs out of memory.
Can we switch bcc to use single instance per bcc process?
And let all kprobes created by given process be in the same instance?

[derek0883]

A good fix for this requires kernel change. the root cause is:
we make 1 instance for each attached function, by default, each instance need allocate 1408KB.
attach hundreds of kprobe will trigger kernel oom-killer, as memory limitation for each process.

#define TRACE_BUF_SIZE_DEFAULT  1441792UL /* 16384 * 88 (sizeof(entry)) */

I think we should revert this patch for now, after make a better handle in kernel side, then try to solve concurrent probes.
Another temporary solution is: when detect large amount of attaching, we avoid to make per-instance attach. But In my opinion, this is not a long-term solution.

@brendangregg @4ast
What do you think, Should I submit another PR to revert, or you can do it directly without PR?

[goldshtn]

Can we create one instance per BCC process and not per attached function?
We could also make this behavior optional - so that scripts that know will need many attaches (like funccount) could opt-out.

[derek0883]

Can we switch bcc to use single instance per bcc process? And let all kprobes created by given process be in the same instance?

I'm trying to find a solution like this, As far as I know, with latest kernel, this still requires kernel changes.
I will update later if I can get some solution.
BTW: does anyone know about perf_trace_run_bpf_submit in kernel, Does this function change the content of event_entry? raw_data of trace_call_bpf ? If we can assume trace_call_bpf will not change the content of event_entry, then things will be easier.

[4ast]

every instance suppose to allocate new trace buffer with this much memory. so i'm not sure what 'kernel changes' you have in mind.

[derek0883]

I did some study before, Currently for my understanding, attach to BPF failed in kernel funtion:

static int perf_event_set_bpf_prog(struct perf_event *event, u32 prog_fd)
{
    if (event->tp_event->prog)
        return -EEXIST;
}

I'm trying to make event->tp_event->prog to a linkList like other link_list in kernel.

1. attaching, Add to that linkList.
2. detaching, Remove from that linkList.
3. event trigger. for each item in linkList, do trace_call_bpf.
   Here is current code in kernel, only do 1 trace_call_bpf call.

void perf_trace_run_bpf_submit(void *raw_data, int size, int rctx,
                   struct trace_event_call *call, u64 count,
                   struct pt_regs *regs, struct hlist_head *head,
                   struct task_struct *task)
{   
    struct bpf_prog *prog = call->prog;

    if (prog) {
        *(struct pt_regs **)raw_data = regs;
        if (!trace_call_bpf(prog, raw_data) || hlist_empty(head)) {
            perf_swevent_put_recursion_context(rctx);
            return;
        }
    }

off course, there are some details need to handle. :)

[vitalyvch]

Could you put some tag on latest working commit?

[goldshtn]

Why do you need a tag? You can checkout by commit: git checkout commithash

[vitalyvch]

From my point of view, it is good practice to mark this kind of commits with tags.

[4ast]

@derek0883 adding link list to kprobe isn't as simple. also I don't see why it's necessary. the user can add multiple kprobes to the same place and attach different programs to those kprobes.
are you planning to fix bcc soon? by making single instance per bcc process as @goldshtn and myself suggested? or some other way? what's an eta?
If it's more than several days, we'd need to revert the offending commit in the mean time, but I'd really like to apply the fix instead.

[derek0883]

@4ast
I submitted a new PR, the fix is easy.
it will create bcc_$pid under instance directory. Then all kprobe attach will use that single instance dir.
Thanks. :)

[vitalyvch]

Guys, I think, it is better to use a result of getprogname() call, instead of "bcc", in instance directory name. What do you think about it?

@4ast, @derek0883, @goldshtn

[brendangregg]

@valkum maybe (better observability), but what if process names have spaces in? Might break things. bcc_$pid is simple and works, but means we'll need to ps -p $pid to see who they are, but that's not a big deal.

The latest fix seems to work:

 # ./funccount.py 'SyS_*'
Tracing 340 functions for "SyS_*"... Hit Ctrl-C to end.
^C
FUNC                                    COUNT
SyS_fstatfs                                 1
SyS_ftruncate                               1
[...]
SyS_read                                  265
SyS_bpf                                   340
SyS_ioctl                                 431
SyS_open                                  530
SyS_close                                 674
SyS_newfstat                              825
Detaching...

[vitalyvch]

@brendangregg I think I will check the latest fix on my system in few hours.

[vitalyvch]

On FC25 fix works excellent. Also I'm going to check on Ubuntu 16.04.

[vitalyvch]

It looks like on my ubuntu also everything is good.

Thanks.

[vitalyvch]

Guys, please rebuilt packages with this fix. Latest packages does not contain it.

[drzaeus77]

@vitalyvch repo server nightly build should now hold the up-to-date packages, can you please check if they work for you?

[vitalyvch]

Yes, latest packages for Ubuntu contain this fix. Thanks.