Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S965273AbdCJOem (ORCPT <rfc822;w@1wt.eu>);
        Fri, 10 Mar 2017 09:34:42 -0500
Received: from shadbolt.e.decadent.org.uk ([88.96.1.126]:42473 "EHLO
        shadbolt.e.decadent.org.uk" rhost-flags-OK-OK-OK-OK)
        by vger.kernel.org with ESMTP id S933443AbdCJLvC (ORCPT
        <rfc822;linux-kernel@vger.kernel.org>);
        Fri, 10 Mar 2017 06:51:02 -0500
Content-Type: text/plain; charset="UTF-8"
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
MIME-Version: 1.0
From: Ben Hutchings <ben@decadent.org.uk>
To: linux-kernel@vger.kernel.org, stable@vger.kernel.org
CC: akpm@linux-foundation.org, "David Ahern" <dsahern@gmail.com>,
        "Arnaldo Carvalho de Melo" <acme@redhat.com>,
        "Namhyung Kim" <namhyung@kernel.org>,
        "Adrian Hunter" <adrian.hunter@intel.com>,
        "Jiri Olsa" <jolsa@kernel.org>, "Wang Nan" <wangnan0@huawei.com>
Date: Fri, 10 Mar 2017 11:46:22 +0000
Message-ID: <lsq.1489146382.107517237@decadent.org.uk>
X-Mailer: LinuxStableQueue (scripts by bwh)
Subject: [PATCH 3.16 009/370] perf trace: Use the syscall raw_syscalls:sys_enter
 timestamp
In-Reply-To: <lsq.1489146380.780052105@decadent.org.uk>
X-SA-Exim-Connect-IP: 82.70.136.246
X-SA-Exim-Mail-From: ben@decadent.org.uk
X-SA-Exim-Scanned: No (on shadbolt.decadent.org.uk); SAEximRunCond expanded to false
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 2615
Lines: 68

3.16.42-rc1 review patch.  If anyone has any objections, please let me know.

------------------

From: Arnaldo Carvalho de Melo <acme@redhat.com>

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
  <SNIP>
     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
  <SNIP>
     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]#

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
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 <acme@redhat.com>
[bwh: Backported to 3.16:
 - Drop changes to trace__printf_interrupted_entry()
 - Adjust context]
Signed-off-by: Ben Hutchings <ben@decadent.org.uk>
---
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1646,7 +1646,7 @@ static int trace__sys_enter(struct trace
 
 	if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
 		if (!trace->duration_filter && !trace->summary_only) {
-			trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output);
+			trace__fprintf_entry_head(trace, thread, 1, ttrace->entry_time, trace->output);
 			fprintf(trace->output, "%-70s\n", ttrace->entry_str);
 		}
 	} else
@@ -1701,7 +1701,7 @@ static int trace__sys_exit(struct trace
 	if (trace->summary_only)
 		goto out;
 
-	trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output);
+	trace__fprintf_entry_head(trace, thread, duration, ttrace->entry_time, trace->output);
 
 	if (ttrace->entry_pending) {
 		fprintf(trace->output, "%-70s", ttrace->entry_str);