From patchwork Wed Jan 31 21:30:01 2024 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Arnaldo Carvalho de Melo X-Patchwork-Id: 194965 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a05:693c:2685:b0:106:209c:c626 with SMTP id mn5csp39910dyc; Wed, 31 Jan 2024 13:39:10 -0800 (PST) X-Google-Smtp-Source: AGHT+IFTvW+31PtXYVnlmtYvGCYZMB6Jv7TdHhuIg0Ka2WrGPgoZCopgU/PP6x7LLRplVJPMjCZ8 X-Received: by 2002:a05:6a20:c31d:b0:19a:112e:89dc with SMTP id dk29-20020a056a20c31d00b0019a112e89dcmr2928921pzb.62.1706737150439; Wed, 31 Jan 2024 13:39:10 -0800 (PST) ARC-Seal: i=2; a=rsa-sha256; t=1706737150; cv=pass; d=google.com; s=arc-20160816; b=PxhZySveTbY+YdPd22tSc3NUq+rS6r8Sv2xSxpuVe6C+sNQrJ01D81HBtJHbt2+5M/ Yr6NCW460PbmvljPnghSlv7fbOw1+0oFPqOs02ir5ZJxuCxz+8pvBieg896580ImHk7p e02RF9L7F9CoKq7x7Fp7+CPb0Va1WOEMAoV9bDUzIkOk3za9mEP5bbcYyw7F6b+Yo0mG G8RvxpyA6UKJcSNu7gZvRkFzjkILIjveFGmi1AQijPVozs8Q+2dqrQHM6J+0Q5TLe7Eo 50LtDr13l0UrJyNM7NM0plz6SI0EX0mNusAsactfDN8LyXIY88Sf968Dezgj56RYIRse V/Pg== ARC-Message-Signature: i=2; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=content-disposition:mime-version:list-unsubscribe:list-subscribe :list-id:precedence:message-id:subject:cc:to:from:date :dkim-signature; bh=oftJ6mCASaFoVyuuw6idt8tNMHN7Rv3MoeTBn7MQpzY=; fh=v1dq/Om6dO3bnNSVblnj/Ci/HvPdCIZBfcaTOlsJGKs=; b=M9M8RxJG/USBoCtfPxafNXeO9pvFK7Ixw2rv5K7buQ+++5kRQ4nReLPCY4zBnKc9j0 StRB9CfCjHLplJu8mIfnonI2TuoukolIZyN50EPcVyAJFATfLxN030BB4d4jBvVP9GVn caHtqGqL937p3WxNgYtQvalUaubcIRHzRtwSqv75bK2SmtFrBQLzg7Yi/yYdBDcHLN7n P93NoLVzQp3C4rupT+c+ssq/G8sWEe6jUng2p8xEv35aT56EWrayRnPxPuVuMoFCHEZh IGorVMueFonyFYDJNFak4JFVntVFux8kSLnLHS+KWU/3FD5HdRgfeE/15HjQW2uIpOT5 mecg==; dara=google.com ARC-Authentication-Results: i=2; mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b=lL5GxUM8; arc=pass (i=1 dkim=pass dkdomain=kernel.org); spf=pass (google.com: domain of linux-kernel+bounces-47172-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:40f1:3f00::1 as permitted sender) smtp.mailfrom="linux-kernel+bounces-47172-ouuuleilei=gmail.com@vger.kernel.org"; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org X-Forwarded-Encrypted: i=1; AJvYcCU6m0o3uSmEAyiuJ2rLEaK8esbJ0zjqKMkMjITXqt4XVzQvshqnBs+tuCEa7xFFB7xIy83CCeaqjXDsZ33B4qvll0qk9Q== Received: from sy.mirrors.kernel.org (sy.mirrors.kernel.org. [2604:1380:40f1:3f00::1]) by mx.google.com with ESMTPS id u33-20020a056a0009a100b006dbd7f1a189si10895599pfg.334.2024.01.31.13.39.10 for (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Wed, 31 Jan 2024 13:39:10 -0800 (PST) Received-SPF: pass (google.com: domain of linux-kernel+bounces-47172-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:40f1:3f00::1 as permitted sender) client-ip=2604:1380:40f1:3f00::1; Authentication-Results: mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b=lL5GxUM8; arc=pass (i=1 dkim=pass dkdomain=kernel.org); spf=pass (google.com: domain of linux-kernel+bounces-47172-ouuuleilei=gmail.com@vger.kernel.org designates 2604:1380:40f1:3f00::1 as permitted sender) smtp.mailfrom="linux-kernel+bounces-47172-ouuuleilei=gmail.com@vger.kernel.org"; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from smtp.subspace.kernel.org (wormhole.subspace.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by sy.mirrors.kernel.org (Postfix) with ESMTPS id 3319BB2738E for ; Wed, 31 Jan 2024 21:32:10 +0000 (UTC) Received: from localhost.localdomain (localhost.localdomain [127.0.0.1]) by smtp.subspace.kernel.org (Postfix) with ESMTP id 18F3C3A8E3; Wed, 31 Jan 2024 21:30:08 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b="lL5GxUM8" Received: from smtp.kernel.org (aws-us-west-2-korg-mail-1.web.codeaurora.org [10.30.226.201]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id AB8763A8CC; Wed, 31 Jan 2024 21:30:04 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=10.30.226.201 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1706736604; cv=none; b=aQq/WWrNC+GGsvKChUIbV1w/F52URBQwKCJdEOJ3g7ESCzAFdV5u0RL4onqvNlFcrVLbF3/mDtQ+laSCSc3JyR2QdwW4lAvI0pxq9HPyefU6fzMBZ4gyEBasv6QeTII7ODZ9Bq5rKKZan1rTXaBeIQDaaAkYuvv3ZAVABzxPGjs= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1706736604; c=relaxed/simple; bh=FN2JscihD3Za9BUNC92yN8oh07Kc0nONt2xuzIQoyLI=; h=Date:From:To:Cc:Subject:Message-ID:MIME-Version:Content-Type: Content-Disposition; b=jtDcaivAavqXkNbQfZ0aHHtnxziewvfycudYCK6+OvCb4sqIAhsR8IeSJMydIsQITwwjeMj4TLgfUBKJ04GlsTZumKAdOnWH7rc7G6DjmKLh1FN87LR8vlqyXQo3mKs0kP5CF8ZZSoyKGo99M9mAyML5EplJ7x4j6RoOLlgMyF0= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b=lL5GxUM8; arc=none smtp.client-ip=10.30.226.201 Received: by smtp.kernel.org (Postfix) with ESMTPSA id E19B5C433C7; Wed, 31 Jan 2024 21:30:03 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1706736604; bh=FN2JscihD3Za9BUNC92yN8oh07Kc0nONt2xuzIQoyLI=; h=Date:From:To:Cc:Subject:From; b=lL5GxUM8vGEs2NHzXiYgPRr9XrRp/the9rww+dnHE/77OQd+8xkegs0xA7gmDeUWu g1N73zju3baMpxXZOgRm9QOmTW0oeeUIjdNTIPg0LtXHjzsPRZOLRo6pC+GcbxrIR3 IwxXJt6MzVKDdjHTI65OjsUKYBYvJSYAit6PjiUyJfG540ZOvmO+av/igkYYG/Zt+s dljcf1c36NWe0+etAIsfrnMEQGphm1jsYEFe8lAmcs40237P9/CU7P/L9ggVv05nlG p7ZWylXbxVsHW2OdLuid3+X0NbUtee9OMp7D/jSrMvxZTJW8qvnA/5boALJlVortwK RUQLpnjc1D8Xg== Received: by quaco.ghostprotocols.net (Postfix, from userid 1000) id 8EC5840441; Wed, 31 Jan 2024 18:30:01 -0300 (-03) Date: Wed, 31 Jan 2024 18:30:01 -0300 From: Arnaldo Carvalho de Melo To: Namhyung Kim Cc: Adrian Hunter , Ian Rogers , Jiri Olsa , Linux Kernel Mailing List , linux-perf-users@vger.kernel.org Subject: [PATCH 1/1] perf trace: Collect sys_nanosleep first argument Message-ID: Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Disposition: inline X-getmail-retrieved-from-mailbox: INBOX X-GMAIL-THRID: 1789643614274644474 X-GMAIL-MSGID: 1789643614274644474 That is a 'struct timespec' passed from userspace to the kernel as we can see with a system wide syscall tracing: root@number:~# perf trace -e nanosleep 0.000 (10.102 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 38.924 (10.077 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 100.177 (10.107 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 139.171 (10.063 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 200.603 (10.105 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 239.399 (10.064 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 300.994 (10.096 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 339.584 (10.067 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 401.335 (10.057 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 439.758 (10.166 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 501.814 (10.110 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 539.983 (10.227 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 602.284 (10.199 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 640.208 (10.105 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 702.662 (10.163 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 740.440 (10.107 ms): podman/2195174 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 802.993 (10.159 ms): podman/9150 nanosleep(rqtp: { .tv_sec: 0, .tv_nsec: 10000000 }) = 0 ^Croot@number:~# strace -p 9150 -e nanosleep If we then use the ptrace method to look at that podman process: root@number:~# strace -p 9150 -e nanosleep strace: Process 9150 attached nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 nanosleep({tv_sec=0, tv_nsec=10000000}, NULL) = 0 ^Cstrace: Process 9150 detached root@number:~# With some changes we can get something closer to the strace output, still in system wide mode: root@number:~# perf config trace.show_arg_names=false root@number:~# perf config trace.show_duration=false root@number:~# perf config trace.show_timestamp=false root@number:~# perf config trace.show_zeros=true root@number:~# perf config trace.args_alignment=0 root@number:~# perf trace -e nanosleep --max-events=10 podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/2195174 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 podman/9150 nanosleep({ .tv_sec: 0, .tv_nsec: 10000000 }, NULL) = 0 root@number:~# root@number:~# perf config trace.show_arg_names=false trace.show_duration=false trace.show_timestamp=false trace.show_zeros=true trace.args_alignment=0 root@number:~# cat ~/.perfconfig # this file is auto-generated. [trace] show_arg_names = false show_duration = false show_timestamp = false show_zeros = true args_alignment = 0 root@number:~# This will not get reused by any other syscall as nanosleep is the only one to have as its first argument a 'struct timespec" pointer argument passed from userspace to the kernel: root@number:~# grep timespec /sys/kernel/tracing/events/syscalls/sys_enter_*/format | grep offset:16 /sys/kernel/tracing/events/syscalls/sys_enter_nanosleep/format: field:struct __kernel_timespec * rqtp; offset:16; size:8; signed:0; root@number:~# BTF based pretty printing will simplify all this, but then lets just get the low hanging fruits first. Cc: Adrian Hunter Cc: Ian Rogers Cc: Jiri Olsa Cc: Namhyung Kim Link: https://lore.kernel.org/lkml/ Signed-off-by: Arnaldo Carvalho de Melo Reviewed-by: Ian Rogers --- tools/perf/builtin-trace.c | 2 ++ .../bpf_skel/augmented_raw_syscalls.bpf.c | 21 +++++++++++++++++++ 2 files changed, 23 insertions(+) diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index 109b8e64fe69ae32..6abe280dc38f1921 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -1048,6 +1048,8 @@ static const struct syscall_fmt syscall_fmts[] = { .arg = { [3] = { .scnprintf = SCA_MREMAP_FLAGS, /* flags */ }, }, }, { .name = "name_to_handle_at", .arg = { [0] = { .scnprintf = SCA_FDAT, /* dfd */ }, }, }, + { .name = "nanosleep", + .arg = { [0] = { .scnprintf = SCA_TIMESPEC, /* req */ }, }, }, { .name = "newfstatat", .arg = { [0] = { .scnprintf = SCA_FDAT, /* dfd */ }, }, }, { .name = "open", diff --git a/tools/perf/util/bpf_skel/augmented_raw_syscalls.bpf.c b/tools/perf/util/bpf_skel/augmented_raw_syscalls.bpf.c index 52c270330ae0d2f3..baecffbece14fb68 100644 --- a/tools/perf/util/bpf_skel/augmented_raw_syscalls.bpf.c +++ b/tools/perf/util/bpf_skel/augmented_raw_syscalls.bpf.c @@ -354,6 +354,27 @@ int sys_enter_clock_nanosleep(struct syscall_enter_args *args) return 1; /* Failure: don't filter */ } +SEC("tp/syscalls/sys_enter_nanosleep") +int sys_enter_nanosleep(struct syscall_enter_args *args) +{ + struct augmented_args_payload *augmented_args = augmented_args_payload(); + const void *req_arg = (const void *)args->args[0]; + unsigned int len = sizeof(augmented_args->args); + __u32 size = sizeof(struct timespec64); + + if (augmented_args == NULL) + goto failure; + + if (size > sizeof(augmented_args->__data)) + goto failure; + + bpf_probe_read_user(&augmented_args->__data, size, req_arg); + + return augmented__output(args, augmented_args, len + size); +failure: + return 1; /* Failure: don't filter */ +} + static pid_t getpid(void) { return bpf_get_current_pid_tgid();