Received: by 2002:a25:1985:0:0:0:0:0 with SMTP id 127csp606159ybz; Wed, 29 Apr 2020 06:16:03 -0700 (PDT) X-Google-Smtp-Source: APiQypJ3Alld6zKuSNNBkp/atTnC13SNxPAYbhlaTwUccpAmaDgaby7aGUqAmK6OVgJ2zIWQbz0A X-Received: by 2002:a17:906:8282:: with SMTP id h2mr2664151ejx.250.1588166163435; Wed, 29 Apr 2020 06:16:03 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1588166163; cv=none; d=google.com; s=arc-20160816; b=akXlSCK64a4UF7AmorCBlqwoe+tY8fm5gh4hplh1GBzgGAs/A4Z6IcCCOUBvI171RM CuVCPG+n84qHL0/d8ctRqBKxqwQjozhIJ0Hpm/slaJSOjrHvwEn41Do0zkif6kMhnT5I f3dtPP7VjbhNPfq5olOQQU8x3cww4WTnxuP4xlZSfC6DUyKeTBL608cBcoWMGtTIVMzM hMSOn2mIwfRwxCekUD0aT66nZAXtyz3hCqTKiLPeHyvIwVkVJ05ALkEremmEyKKBy1RJ r3QuJC5T3B4NxJWGD50vsc0FrByUQZ6DRkaRgNiF1XOyleg18G/vwEm1FjnSVgKC/vTU fM7Q== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:sender:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from :dkim-signature; bh=3w4pki/cxUEawUt5bMV2kSGbGDi3LOFAPAVl8i8C06M=; b=NG/ykga7dgpoHfH8nu2s75ri3PqL/hqdSjLTTKSjYIixxsJo5fKtbSl7s+JaDHKQK0 8gh8FYFXJWokN9yxvgiuibJPPnh0YzCqZCNGZL0bz+Pgqje4CkwB//9wrd9fBc39Z4A/ rRrfi3pT50A2PCPD5GlpTBX867Zipv2SvfFOQwL0uh0wDclLlNXn9PR8k+bYtBsErDWv thCrzIt193YByP7mAt/x8L/veOYGN5IZYN/M6da8HAuyglGHgVHSfYx8CTaxB3isYqHL rB88f2fo4Uln7nU8Z0kaLAHaVqJNklw3qSHUJCDMxiawUWBsZZ9AebyHZK84FmnqlHC/ 3A2A== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@kernel.org header.s=default header.b="zA6dA8A/"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Return-Path: Received: from vger.kernel.org (vger.kernel.org. [23.128.96.18]) by mx.google.com with ESMTP id n13si983406edq.352.2020.04.29.06.15.38; Wed, 29 Apr 2020 06:16:03 -0700 (PDT) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18; Authentication-Results: mx.google.com; dkim=pass header.i=@kernel.org header.s=default header.b="zA6dA8A/"; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1726892AbgD2NLi (ORCPT + 99 others); Wed, 29 Apr 2020 09:11:38 -0400 Received: from mail.kernel.org ([198.145.29.99]:48710 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1726960AbgD2NLf (ORCPT ); Wed, 29 Apr 2020 09:11:35 -0400 Received: from quaco.ghostprotocols.net (unknown [179.97.37.151]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPSA id 6004C22245; Wed, 29 Apr 2020 13:11:31 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=default; t=1588165894; bh=5nq80OBqIbEjTw6LmVz6/qZCKOUv/VeL2jI+k4fJdqI=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=zA6dA8A/vRaNz3Nn/jBFyYqaTREUMG+LJf9PKwYpFwwsz0+G7qwfunuwvksuJDDQY ZBGtDhrjtZri5/TWAP0KCa9F1elFPR58tAmrULoZ8EIcwOIvSRP6O3Agv1OyK82AiI 9Stq/gRCw5vyOtcIqumhzVLeX++41Cf6+9sp5r1Y= From: Arnaldo Carvalho de Melo To: Jiri Olsa , Namhyung Kim Cc: Ingo Molnar , Thomas Gleixner , Clark Williams , linux-kernel@vger.kernel.org, linux-perf-users@vger.kernel.org, Arnaldo Carvalho de Melo , Adrian Hunter , Song Liu , Wang Nan Subject: [PATCH 7/8] perf record: Introduce --switch-output-event Date: Wed, 29 Apr 2020 10:11:05 -0300 Message-Id: <20200429131106.27974-8-acme@kernel.org> X-Mailer: git-send-email 2.21.1 In-Reply-To: <20200429131106.27974-1-acme@kernel.org> References: <20200429131106.27974-1-acme@kernel.org> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org From: Arnaldo Carvalho de Melo Now we can use it with --overwrite to have a flight recorder mode that gets snapshot requests from arbitrary events that are processed in the side band thread together with the PERF_RECORD_BPF_EVENT processing. Example: To collect scheduler events until a recvmmsg syscall happens, system wide: [root@five a]# rm -f perf.data.2020042717* [root@five a]# perf record --overwrite -e sched:*switch,syscalls:*recvmmsg --switch-output-event syscalls:sys_enter_recvmmsg [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042717585458 ] [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042717590235 ] [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042717590398 ] ^C[ perf record: Woken up 1 times to write data ] [ perf record: Dump perf.data.2020042717590511 ] [ perf record: Captured and wrote 7.244 MB perf.data. ] So in the above case we had 3 snapshots, the fourth was forced by control+C: [root@five a]# ls -la total 20440 drwxr-xr-x. 2 root root 4096 Apr 27 17:59 . dr-xr-x---. 12 root root 4096 Apr 27 17:46 .. -rw-------. 1 root root 3936125 Apr 27 17:58 perf.data.2020042717585458 -rw-------. 1 root root 5074869 Apr 27 17:59 perf.data.2020042717590235 -rw-------. 1 root root 4291037 Apr 27 17:59 perf.data.2020042717590398 -rw-------. 1 root root 7617037 Apr 27 17:59 perf.data.2020042717590511 [root@five a]# One can make this more precise by adding the switch output event to the main -e events list, as since this is done asynchronously, a few events after the signal event will appear in the snapshots, as can be seen with: [root@five a]# rm -f perf.data.20200427175* [root@five a]# perf record --overwrite -e sched:*switch,syscalls:*recvmmsg --switch-output-event syscalls:sys_enter_recvmmsg [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042718024203 ] [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042718024301 ] [ perf record: dump data: Woken up 1 times ] [ perf record: Dump perf.data.2020042718024484 ] ^C[ perf record: Woken up 1 times to write data ] [ perf record: Dump perf.data.2020042718024562 ] [ perf record: Captured and wrote 7.337 MB perf.data. ] [root@five a]# perf script -i perf.data.2020042718024203 | tail -15 PacerThread 148586 [005] 122.830729: sched:sched_switch: prev_comm=PacerThread prev_pid=148586... swapper 0 [000] 122.833588: sched:sched_switch: prev_comm=swapper/0 prev_pid=... NetworkManager 1251 [000] 122.833619: syscalls:sys_enter_recvmmsg: fd: 0x0000001c, mmsg: 0x7ffe83054a1... swapper 0 [002] 122.833624: sched:sched_switch: prev_comm=swapper/2 prev_pid=... swapper 0 [003] 122.833624: sched:sched_switch: prev_comm=swapper/3 prev_pid=... NetworkManager 1251 [000] 122.833626: syscalls:sys_exit_recvmmsg: 0x1 kworker/3:3-eve 158946 [003] 122.833628: sched:sched_switch: prev_comm=kworker/3:3 prev_pid=15894... swapper 0 [004] 122.833641: sched:sched_switch: prev_comm=swapper/4 prev_pid=... NetworkManager 1251 [000] 122.833642: sched:sched_switch: prev_comm=NetworkManage... perf 228273 [002] 122.833645: sched:sched_switch: prev_comm=perf prev_pid=22827... swapper 0 [011] 122.833646: sched:sched_switch: prev_comm=swapper/1... swapper 0 [002] 122.833648: sched:sched_switch: prev_comm=swapper/... kworker/0:2-eve 207387 [000] 122.833648: sched:sched_switch: prev_comm=kworker/0:2 prev_pid=20738... kworker/2:3-eve 232038 [002] 122.833652: sched:sched_switch: prev_comm=kworker/2:3 prev_pid=23203... perf 235825 [003] 122.833653: sched:sched_switch: prev_comm=perf prev_pid=23582... [root@five a]# Cc: Adrian Hunter Cc: Jiri Olsa Cc: Namhyung Kim Cc: Song Liu Cc: Wang Nan Link: http://lore.kernel.org/lkml/20200427211935.25789-8-acme@kernel.org Link: http://lore.kernel.org/lkml/20200428121601.GB2245@kernel.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/perf/Documentation/perf-record.txt | 13 ++++++++ tools/perf/builtin-record.c | 41 +++++++++++++++++++++--- 2 files changed, 50 insertions(+), 4 deletions(-) diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt index 6e8b4649307c..561ef55743e2 100644 --- a/tools/perf/Documentation/perf-record.txt +++ b/tools/perf/Documentation/perf-record.txt @@ -556,6 +556,19 @@ overhead. You can still switch them on with: --switch-output --no-no-buildid --no-no-buildid-cache +--switch-output-event:: +Events that will cause the switch of the perf.data file, auto-selecting +--switch-output=signal, the results are similar as internally the side band +thread will also send a SIGUSR2 to the main one. + +Uses the same syntax as --event, it will just not be recorded, serving only to +switch the perf.data file as soon as the --switch-output event is processed by +a separate sideband thread. + +This sideband thread is also used to other purposes, like processing the +PERF_RECORD_BPF_EVENT records as they happen, asking the kernel for extra BPF +information, etc. + --switch-max-files=N:: When rotating perf.data with --switch-output, only keep N files. diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c index ed2244847400..7a6a89972691 100644 --- a/tools/perf/builtin-record.c +++ b/tools/perf/builtin-record.c @@ -87,7 +87,9 @@ struct record { struct evlist *evlist; struct perf_session *session; struct evlist *sb_evlist; + pthread_t thread_id; int realtime_prio; + bool switch_output_event_set; bool no_buildid; bool no_buildid_set; bool no_buildid_cache; @@ -1436,6 +1438,13 @@ static int record__synthesize(struct record *rec, bool tail) return err; } +static int record__process_signal_event(union perf_event *event __maybe_unused, void *data) +{ + struct record *rec = data; + pthread_kill(rec->thread_id, SIGUSR2); + return 0; +} + static int __cmd_record(struct record *rec, int argc, const char **argv) { int err; @@ -1580,12 +1589,24 @@ static int __cmd_record(struct record *rec, int argc, const char **argv) goto out_child; } - if (!opts->no_bpf_event) { - rec->sb_evlist = evlist__new(); + if (rec->sb_evlist != NULL) { + /* + * We get here if --switch-output-event populated the + * sb_evlist, so associate a callback that will send a SIGUSR2 + * to the main thread. + */ + evlist__set_cb(rec->sb_evlist, record__process_signal_event, rec); + rec->thread_id = pthread_self(); + } + if (!opts->no_bpf_event) { if (rec->sb_evlist == NULL) { - pr_err("Couldn't create side band evlist.\n."); - goto out_child; + rec->sb_evlist = evlist__new(); + + if (rec->sb_evlist == NULL) { + pr_err("Couldn't create side band evlist.\n."); + goto out_child; + } } if (evlist__add_bpf_sb_event(rec->sb_evlist, &session->header.env)) { @@ -2179,10 +2200,19 @@ static int switch_output_setup(struct record *rec) }; unsigned long val; + /* + * If we're using --switch-output-events, then we imply its + * --switch-output=signal, as we'll send a SIGUSR2 from the side band + * thread to its parent. + */ + if (rec->switch_output_event_set) + goto do_signal; + if (!s->set) return 0; if (!strcmp(s->str, "signal")) { +do_signal: s->signal = true; pr_debug("switch-output with SIGUSR2 signal\n"); goto enabled; @@ -2440,6 +2470,9 @@ static struct option __record_options[] = { &record.switch_output.set, "signal or size[BKMG] or time[smhd]", "Switch output when receiving SIGUSR2 (signal) or cross a size or time threshold", "signal"), + OPT_CALLBACK_SET(0, "switch-output-event", &record.sb_evlist, &record.switch_output_event_set, "switch output event", + "switch output event selector. use 'perf list' to list available events", + parse_events_option_new_evlist), OPT_INTEGER(0, "switch-max-files", &record.switch_output.num_files, "Limit number of switch output generated files"), OPT_BOOLEAN(0, "dry-run", &dry_run, -- 2.21.1