netdev - Re: [PATCH v3 bpf-next 1/3] bpftool: introduce "prog profile" command

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <0140e565-55c0-7025-dfbb-88f644532c6a@isovalent.com>
Date:   Wed, 4 Mar 2020 10:59:35 +0000
From:   Quentin Monnet <quentin@...valent.com>
To:     Song Liu <songliubraving@...com>, netdev@...r.kernel.org,
        bpf@...r.kernel.org
Cc:     kernel-team@...com, ast@...nel.org, daniel@...earbox.net,
        arnaldo.melo@...il.com, jolsa@...nel.org
Subject: Re: [PATCH v3 bpf-next 1/3] bpftool: introduce "prog profile" command

2020-03-03 11:55 UTC-0800 ~ Song Liu <songliubraving@...com>
> With fentry/fexit programs, it is possible to profile BPF program with
> hardware counters. Introduce bpftool "prog profile", which measures key
> metrics of a BPF program.
> 
> bpftool prog profile command creates per-cpu perf events. Then it attaches
> fentry/fexit programs to the target BPF program. The fentry program saves
> perf event value to a map. The fexit program reads the perf event again,
> and calculates the difference, which is the instructions/cycles used by
> the target program.
> 
> Example input and output:
> 
>   ./bpftool prog profile id 337 duration 3 cycles instructions llc_misses
> 
>         4228 run_cnt
>      3403698 cycles                                              (84.08%)
>      3525294 instructions   #  1.04 insn per cycle               (84.05%)
>           13 llc_misses     #  3.69 LLC misses per million isns  (83.50%)
> 
> This command measures cycles and instructions for BPF program with id
> 337 for 3 seconds. The program has triggered 4228 times. The rest of the
> output is similar to perf-stat. In this example, the counters were only
> counting ~84% of the time because of time multiplexing of perf counters.
> 
> Note that, this approach measures cycles and instructions in very small
> increments. So the fentry/fexit programs introduce noticeable errors to
> the measurement results.
> 
> The fentry/fexit programs are generated with BPF skeletons. Therefore, we
> build bpftool twice. The first time _bpftool is built without skeletons.
> Then, _bpftool is used to generate the skeletons. The second time, bpftool
> is built with skeletons.
> 
> Signed-off-by: Song Liu <songliubraving@...com>
> ---

Hi Song, thank you for all the changes! Just found a couple more things
below, sorry I missed them on the v2.

[...]

> --- a/tools/bpf/bpftool/prog.c
> +++ b/tools/bpf/bpftool/prog.c

[...]

> +static int profile_open_perf_events(struct profiler_bpf *obj)
> +{
> +	unsigned int cpu, m;
> +	int map_fd, pmu_fd;
> +
> +	profile_perf_events = calloc(
> +		sizeof(int), obj->rodata->num_cpu * obj->rodata->num_metric);
> +	if (!profile_perf_events) {
> +		p_err("failed to allocate memory for perf_event array: %s",
> +		      strerror(errno));
> +		return -1;
> +	}
> +	map_fd = bpf_map__fd(obj->maps.events);
> +	if (map_fd < 0) {
> +		p_err("failed to get fd for events map");
> +		return -1;
> +	}
> +
> +	for (m = 0; m < ARRAY_SIZE(metrics); m++) {
> +		if (!metrics[m].selected)
> +			continue;
> +		for (cpu = 0; cpu < obj->rodata->num_cpu; cpu++) {
> +			pmu_fd = syscall(__NR_perf_event_open, &metrics[m].attr,
> +					 -1/*pid*/, cpu, -1/*group_fd*/, 0);
> +			if (pmu_fd < 0 ||
> +			    bpf_map_update_elem(map_fd, &profile_perf_event_cnt,
> +						&pmu_fd, BPF_ANY) ||
> +			    ioctl(pmu_fd, PERF_EVENT_IOC_ENABLE, 0)) {
> +				p_err("failed to create event %s on cpu %d",
> +				      metrics[m].name, cpu);
> +				goto err;

You can probably simply return here...

> +			}
> +			profile_perf_events[profile_perf_event_cnt++] = pmu_fd;
> +		}
> +	}
> +	return 0;
> +err:
> +	profile_close_perf_events(profile_obj);
> +	return -1;

... and remove the "err:" label here, because if I understand correctly
the only call to profile_open_perf_events() is in do_profile() (below),
and if it fails, "profile_close_perf_events(profile_obj);" is called there.

> +}

[...]

> +static int do_profile(int argc, char **argv)
> +{

[...]

> +	err = profile_open_perf_events(profile_obj);
> +	if (err) {
> +		p_err("failed to open perf events");

Also do you think we can remove this p_err() (or move the text in
profile_open_perf_events() error messages)? This is because
profile_open_perf_events() already prints something if it fails, and
error messages work best with JSON if there is just one at a time.

Would also apply to profile_target_name() a few lines above.

> +		goto out;
> +	}
> +
> +	err = profiler_bpf__attach(profile_obj);
> +	if (err) {
> +		p_err("failed to attach profile_obj");
> +		goto out;
> +	}
> +	signal(SIGINT, int_exit);
> +
> +	sleep(duration);
> +	profile_print_and_cleanup();
> +	return 0;
> +
> +out:
> +	profile_close_perf_events(profile_obj);
> +	if (profile_obj)
> +		profiler_bpf__destroy(profile_obj);
> +	close(profile_tgt_fd);
> +	free(profile_tgt_name);
> +	return err;
> +}