This message generated a parse failure. Raw output follows here. Please use 'back' to navigate. From devnull@lkml.org Wed Jun 12 11:36:13 2024 >From mailfetcher Fri Aug 11 20:48:02 2023 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on pi4 X-Spam-Level: X-Spam-Status: No, score=-1.3 required=5.0 tests=DKIMWL_WL_HIGH,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,DMARC_PASS,MAILING_LIST_MULTI, SPF_HELO_NONE,SPF_PASS autolearn=ham autolearn_force=no version=3.4.6 Authentication-Results: pi4.bmw12.nl; dmarc=pass (p=none dis=none) header.from=kernel.org Authentication-Results: pi4.bmw12.nl; dkim=pass (Good 2048 bit rsa-sha256 signature) header.d=kernel.org header.a=rsa-sha256 Authentication-Results: pi4.bmw12.nl; spf=pass (sender SPF authorized) smtp.mailfrom=vger.kernel.org (client-ip=2620:137:e000::1:20; helo=out1.vger.email; envelope-from=linux-kernel-owner@vger.kernel.org; receiver=) Received: from secure.jasper.es [188.166.10.231] by 1dc7d414a5be with IMAP (fetchmail-6.3.26) for (single-drop); Fri, 11 Aug 2023 20:48:02 +0200 (CEST) Received: from out1.vger.email (out1.vger.email [IPv6:2620:137:e000::1:20]) by pi4.bmw12.nl (Postfix) with ESMTP id 221553F052 for ; Fri, 11 Aug 2023 20:47:59 +0200 (CEST) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S235932AbjHKSqu (ORCPT ); Fri, 11 Aug 2023 14:46:50 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:56618 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S233418AbjHKSqt (ORCPT ); Fri, 11 Aug 2023 14 Received: from dfw.source.kernel.org (dfw.source.kernel.org [IPv6:2604:1380:4641:c500::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 67F9430E6; Fri, 11 Aug 2023 11:46:48 -0700 (PDT) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by dfw.sourc Received: by smtp.kernel.org (Postfix) with ESMTPSA id E5951C433C7; Fri, 11 Aug 2023 18:46:46 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1691779607; bh=nDDxGEV4teeqKODzITrojrRa6y1Se5dQWQloauuO9uk=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From; b=aKzDemCRFW9rclhVY3pUXg56W7JyHbhDaCsz6RR7hK Received: by quaco.ghostprotocols.net (Postfix, from userid 1000) id 237A2404DF; Fri, 11 Aug 2023 15:46:44 -0300 (-03) Date: Fri, 11 Aug 2023 15:46:44 -0300 From: Arnaldo Carvalho de Melo To: Ian Rogers Cc: Peter Zijlstra , Ingo Molnar , Mark Rutland , Alexander Shishkin , Jiri Olsa , Namhyung Kim References: <20230810184853.2860737-1-irogers@google.com> <20230810184853.2860737-3-irogers@google.com> Mime-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline Content-Transfer-Encoding: quoted-printable In-Reply-To: <20230810184853.2860737-3-irogers@google.com> X-URL: http://acmel.wordpress.com Precedence: bulk List-Id: X-Mailing-List: linux-kernel@vger.kernel.org Em Thu, Aug 10, 2023 at 11:48:51AM -0700, Ian Rogers escreveu: > Previously a BPF event of augmented_raw_syscalls.c could be used to > enable augmentation of syscalls by perf trace. As BPF events are no > longer supported, switch to using a BPF skeleton which when attached > explicitly opens the sysenter and sysexit tracepoints. >=20 > The dump map is removed as debugging wasn't supported by the > augmentation and bpf_printk can be used when necessary. >=20 > Remove tools/perf/examples/bpf/augmented_raw_syscalls.c so that the > rename/migration to a BPF skeleton captures that this was the source. So, there is a problem where the augmented_raw_syscalls connect/sendto handlers are being rejected by the verifier, the way you did it makes it to print the verifier output and then continue without augmentation, unsure if this is a good default, opinions? [root@quaco ~]# perf trace -e open* libbpf: prog 'sys_enter_connect': BPF program load failed: Permission denied libbpf: prog 'sys_enter_connect': -- BEGIN PROG LOAD LOG -- reg type unsupported for arg#0 function sys_enter_connect#59 0: R1=3Dctx(off=3D0,imm=3D0) R10=3Dfp0 ; int sys_enter_connect(struct syscall_enter_args *args) 0: (bf) r6 =3D r1 ; R1=3Dctx(off=3D0,imm=3D0) R6_w=3D= ctx(off=3D0,imm=3D0) 1: (b7) r1 =3D 0 ; R1_w=3D0 ; int key =3D 0; 2: (63) *(u32 *)(r10 -4) =3D r1 ; R1_w=3D0 R10=3Dfp0 fp-8=3D0000???? 3: (bf) r2 =3D r10 ; R2_w=3Dfp0 R10=3Dfp0 ; 4: (07) r2 +=3D -4 ; R2_w=3Dfp-4 ; return bpf_map_lookup_elem(&augmented_args_tmp, &key); 5: (18) r1 =3D 0xffff8de5ae1d4600 ; R1_w=3Dmap_ptr(off=3D0,ks=3D4,vs= =3D8272,imm=3D0) 7: (85) call bpf_map_lookup_elem#1 ; R0_w=3Dmap_value_or_null(id=3D1,off= =3D0,ks=3D4,vs=3D8272,imm=3D0) 8: (bf) r7 =3D r0 ; R0_w=3Dmap_value_or_null(id=3D1,o= ff=3D0,ks=3D4,vs=3D8272,imm=3D0) R7_w=3Dmap_value_or_null(id=3D1,off=3D0,ks= =3D4,vs=3D8272,imm=3D0) 9: (b7) r0 =3D 1 ; R0_w=3D1 ; if (augmented_args =3D=3D NULL) 10: (15) if r7 =3D=3D 0x0 goto pc+25 ; R7_w=3Dmap_value(off=3D0,ks=3D4= ,vs=3D8272,imm=3D0) ; unsigned int socklen =3D args->args[2]; 11: (79) r1 =3D *(u64 *)(r6 +32) ; R1_w=3Dscalar() R6_w=3Dctx(off=3D= 0,imm=3D0) ; 12: (bf) r2 =3D r1 ; R1_w=3Dscalar(id=3D2) R2_w=3Dscal= ar(id=3D2) 13: (67) r2 <<=3D 32 ; R2_w=3Dscalar(smax=3D922337203255= 9808512,umax=3D18446744069414584320,var_off=3D(0x0; 0xffffffff00000000),s32= _min=3D0,s32_max=3D0,u32_max=3D0) 14: (77) r2 >>=3D 32 ; R2_w=3Dscalar(umax=3D4294967295,v= ar_off=3D(0x0; 0xffffffff)) 15: (b7) r8 =3D 128 ; R8=3D128 ; if (socklen > sizeof(augmented_args->saddr)) 16: (25) if r2 > 0x80 goto pc+1 ; R2=3Dscalar(umax=3D128,var_off=3D(0= x0; 0xff)) 17: (bf) r8 =3D r1 ; R1=3Dscalar(id=3D2) R8_w=3Dscalar= (id=3D2) ; const void *sockaddr_arg =3D (const void *)args->args[1]; 18: (79) r3 =3D *(u64 *)(r6 +24) ; R3_w=3Dscalar() R6=3Dctx(off=3D0,= imm=3D0) ; bpf_probe_read(&augmented_args->saddr, socklen, sockaddr_arg); 19: (bf) r1 =3D r7 ; R1_w=3Dmap_value(off=3D0,ks=3D4,v= s=3D8272,imm=3D0) R7=3Dmap_value(off=3D0,ks=3D4,vs=3D8272,imm=3D0) 20: (07) r1 +=3D 64 ; R1_w=3Dmap_value(off=3D64,ks=3D4,= vs=3D8272,imm=3D0) ; bpf_probe_read(&augmented_args->saddr, socklen, sockaddr_arg); 21: (bf) r2 =3D r8 ; R2_w=3Dscalar(id=3D2) R8_w=3Dscal= ar(id=3D2) 22: (85) call bpf_probe_read#4 R2 min value is negative, either use unsigned or 'var &=3D const' processed 22 insns (limit 1000000) max_states_per_insn 0 total_states 1 pea= k_states 1 mark_read 1 -- END PROG LOAD LOG -- libbpf: prog 'sys_enter_connect': failed to load: -13 libbpf: failed to load object 'augmented_raw_syscalls_bpf' libbpf: failed to load BPF skeleton 'augmented_raw_syscalls_bpf': -13 0.000 systemd-oomd/959 openat(dfd: CWD, filename: 0xc0a2a2bd, flags: R= DONLY|CLOEXEC) =3D 12 86.339 thermald/1234 openat(dfd: CWD, filename: 0xac000ba0) =3D 13 87.008 thermald/1234 openat(dfd: CWD, filename: 0xac000eb0) =3D 13 87.270 thermald/1234 openat(dfd: CWD, filename: 0xac000b70) =3D 13 89.657 thermald/1234 openat(dfd: CWD, filename: 0xac000eb0) =3D 13 ^C If I comment out the connect and sendto it doesn't build anymore, whereas before it would continue with the other handlers: CLANG /tmp/build/perf-tools-next/util/bpf_skel/.tmp/augmented_raw_sysca= lls.bpf.o GENSKEL /tmp/build/perf-tools-next/util/bpf_skel/augmented_raw_syscalls.s= kel.h CC /tmp/build/perf-tools-next/builtin-trace.o builtin-trace.c: In function =E2=80=98cmd_trace=E2=80=99: builtin-trace.c:4873:63: error: =E2=80=98struct =E2=80=99 has no= member named =E2=80=98sys_enter_connect=E2=80=99; did you mean =E2=80=98sy= s_enter_openat=E2=80=99? 4873 | bpf_program__set_autoattach(trace.skel->progs.sys_e= nter_connect, | ^~~~~= ~~~~~~~~~~~~ | sys_e= nter_openat builtin-trace.c:4875:63: error: =E2=80=98struct =E2=80=99 has no= member named =E2=80=98sys_enter_sendto=E2=80=99; did you mean =E2=80=98sys= _enter_openat=E2=80=99? 4875 | bpf_program__set_autoattach(trace.skel->progs.sys_e= nter_sendto, | ^~~~~= ~~~~~~~~~~~ | sys_e= nter_openat make[3]: *** [/home/acme/git/perf-tools-next/tools/build/Makefile.build:97:= /tmp/build/perf-tools-next/builtin-trace.o] Error 1 make[2]: *** [Makefile.perf:662: /tmp/build/perf-tools-next/perf-in.o] Erro= r 2 make[1]: *** [Makefile.perf:238: sub-make] Error 2 make: *** [Makefile:113: install-bin] Error 2 make: Leaving directory '/home/acme/git/perf-tools-next/tools/perf' [acme@quaco perf-tools-next]$ =1A I.e. no need for explicitely referring to those, I think in the past it was just looking if it was there and if so, attaching, I'll try to fix this. If I remove the explicit references in builtin-trace.c: [root@quaco ~]# perf trace -e open* --max-events=3D10 0.000 thermald/1234 openat(dfd: CWD, filename: "/sys/class/powercap/in= tel-rapl/intel-rapl:0/intel-rapl:0:2/energy_uj") =3D 13 0.236 thermald/1234 openat(dfd: CWD, filename: "/sys/class/powercap/in= tel-rapl/intel-rapl:0/energy_uj") =3D 13 0.334 thermald/1234 openat(dfd: CWD, filename: "/sys/class/thermal/the= rmal_zone2/temp") =3D 13 9.092 systemd-oomd/959 openat(dfd: CWD, filename: "/proc/meminfo", fla= gs: RDONLY|CLOEXEC) =3D 12 259.212 systemd-oomd/959 openat(dfd: CWD, filename: "/proc/meminfo", fla= gs: RDONLY|CLOEXEC) =3D 12 497.464 gpm/1049 openat(dfd: CWD, filename: "/dev/tty0") =3D 4 509.044 systemd-oomd/959 openat(dfd: CWD, filename: "/proc/meminfo", fla= gs: RDONLY|CLOEXEC) =3D 12 509.559 systemd-oomd/959 openat(dfd: CWD, filename: "/sys/fs/cgroup/user= =2Eslice/user-1000.slice/user@1000.service/session.slice/memory.pressure", = flags: RDONLY|CLOEXEC) =3D 12 509.917 systemd-oomd/959 openat(dfd: CWD, filename: "/sys/fs/cgroup/user= =2Eslice/user-1000.slice/user@1000.service/session.slice/memory.current", f= lags: RDONLY|CLOEXEC) =3D 12 510.111 systemd-oomd/959 openat(dfd: CWD, filename: "/sys/fs/cgroup/user= =2Eslice/user-1000.slice/user@1000.service/session.slice/memory.min", flags= : RDONLY|CLOEXEC) =3D 12 [root@quaco ~]# Cool! Some inception: [root@quaco ~]# perf trace -e perf_event_open perf stat -e cycles,instructi= ons,cache-misses sleep 1 0.000 perf_event_open(attr_uptr: { type: 0 (PERF_TYPE_HARDWARE), size:= 136, config: 0 (PERF_COUNT_HW_CPU_CYCLES), sample_type: IDENTIFIER, read_f= ormat: TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING, disabled: 1, inherit: 1, enab= le_on_exec: 1, exclude_guest: 1 }, pid: 232297 (perf), cpu: -1, group_fd: -= 1, flags: FD_CLOEXEC) =3D 3 0.063 perf_event_open(attr_uptr: { type: 0 (PERF_TYPE_HARDWARE), size:= 136, config: 0x1 (PERF_COUNT_HW_INSTRUCTIONS), sample_type: IDENTIFIER, re= ad_format: TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING, disabled: 1, inherit: 1, = enable_on_exec: 1, exclude_guest: 1 }, pid: 232297 (perf), cpu: -1, group_f= d: -1, flags: FD_CLOEXEC) =3D 4 0.070 perf_event_open(attr_uptr: { type: 0 (PERF_TYPE_HARDWARE), size:= 136, config: 0x3 (PERF_COUNT_HW_CACHE_MISSES), sample_type: IDENTIFIER, re= ad_format: TOTAL_TIME_ENABLED|TOTAL_TIME_RUNNING, disabled: 1, inherit: 1, = enable_on_exec: 1, exclude_guest: 1 }, pid: 232297 (perf), cpu: -1, group_f= d: -1, flags: FD_CLOEXEC) =3D 5 Performance counter stats for 'sleep 1': 2,669,464 cycles 1,842,319 instructions # 0.69 insn pe= r cycle 27,716 cache-misses 1.001948592 seconds time elapsed 0.000000000 seconds user 0.001657000 seconds sys [root@quaco ~]# I'm putting what I have in the tmp.perf-tools-next branch, will continue later today. - Arnaldo