Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753297AbdFGXFR (ORCPT ); Wed, 7 Jun 2017 19:05:17 -0400 Received: from wtarreau.pck.nerim.net ([62.212.114.60]:50661 "EHLO 1wt.eu" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753243AbdFGXFL (ORCPT ); Wed, 7 Jun 2017 19:05:11 -0400 From: Willy Tarreau To: linux-kernel@vger.kernel.org, stable@vger.kernel.org, linux@roeck-us.net Cc: Arnaldo Carvalho de Melo , Adrian Hunter , David Ahern , Jiri Olsa , Namhyung Kim , Wang Nan , Jiri Slaby , Willy Tarreau Subject: [PATCH 3.10 225/250] perf trace: Use the syscall raw_syscalls:sys_enter timestamp Date: Thu, 8 Jun 2017 01:00:11 +0200 Message-Id: <1496876436-32402-226-git-send-email-w@1wt.eu> X-Mailer: git-send-email 2.8.0.rc2.1.gbe9624a In-Reply-To: <1496876436-32402-1-git-send-email-w@1wt.eu> References: <1496876436-32402-1-git-send-email-w@1wt.eu> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 2807 Lines: 73 From: Arnaldo Carvalho de Melo commit ecf1e2253ea79c6204f4d6a5e756e8fb4aed5a7e upstream. Instead of the one when another syscall takes place while another is being processed (in another CPU, but we show it serialized, so need to "interrupt" the other), and also when finally showing the sys_enter + sys_exit + duration, where we were showing the sample->time for the sys_exit, duh. Before: # perf trace sleep 1 0.373 ( 0.001 ms): close(fd: 3 ) = 0 1000.626 (1000.211 ms): nanosleep(rqtp: 0x7ffd6ddddfb0) = 0 1000.653 ( 0.003 ms): close(fd: 1 ) = 0 1000.657 ( 0.002 ms): close(fd: 2 ) = 0 1000.667 ( 0.000 ms): exit_group( ) # After: # perf trace sleep 1 0.336 ( 0.001 ms): close(fd: 3 ) = 0 0.373 (1000.086 ms): nanosleep(rqtp: 0x7ffe303e9550) = 0 1000.481 ( 0.002 ms): close(fd: 1 ) = 0 1000.485 ( 0.001 ms): close(fd: 2 ) = 0 1000.494 ( 0.000 ms): exit_group( ) [root@jouet linux]# [js] no trace__printf_interrupted_entry in 3.12 yet Cc: Adrian Hunter Cc: David Ahern Cc: Jiri Olsa Cc: Namhyung Kim Cc: Wang Nan Link: http://lkml.kernel.org/n/tip-ecbzgmu2ni6glc6zkw8p1zmx@git.kernel.org Fixes: 752fde44fd1c ("perf trace: Support interrupted syscalls") Signed-off-by: Arnaldo Carvalho de Melo Signed-off-by: Jiri Slaby [wt: 3.10 uses stdout instead of trace->output ; no trace__printf_interrupted_entry() function ] Signed-off-by: Willy Tarreau --- tools/perf/builtin-trace.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c index ab3ed4a..9f2afbd 100644 --- a/tools/perf/builtin-trace.c +++ b/tools/perf/builtin-trace.c @@ -330,7 +330,7 @@ static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel, if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) { if (!trace->duration_filter) { - trace__fprintf_entry_head(trace, thread, 1, sample->time, stdout); + trace__fprintf_entry_head(trace, thread, 1, ttrace->entry_time, stdout); printf("%-70s\n", ttrace->entry_str); } } else @@ -364,7 +364,7 @@ static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel, } else if (trace->duration_filter) goto out; - trace__fprintf_entry_head(trace, thread, duration, sample->time, stdout); + trace__fprintf_entry_head(trace, thread, duration, ttrace->entry_time, stdout); if (ttrace->entry_pending) { printf("%-70s", ttrace->entry_str); -- 2.8.0.rc2.1.gbe9624a