From: Kan Liang <[email protected]>
System wide sampling like 'perf top' or 'perf record -a' read all
threads /proc/xxx/maps before sampling. If there are any threads which
generating a keeping growing huge maps, perf will do infinite loop
during synthesizing. Nothing will be sampled.
This patch fixes this issue by adding per-thread timeout to force stop
this kind of endless proc map processing.
PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is introduced to indicate that
the mmap record are truncated by time out. User will get warning
notification when truncated mmap records are detected.
Reported-by: Huang, Ying <[email protected]>
Signed-off-by: Kan Liang <[email protected]>
---
Changes since V1
- Add warning message for time out.
Changes since V2
- Handle time out warning in perf_session__warn_about_errors
- Configurable time out (patch 2/2)
Changes since V3
- Set default timeout to 500ms
- Rename some variables and macros
include/uapi/linux/perf_event.h | 4 ++++
tools/perf/util/event.c | 18 ++++++++++++++++++
tools/perf/util/event.h | 1 +
tools/perf/util/session.c | 11 +++++++++++
4 files changed, 34 insertions(+)
diff --git a/include/uapi/linux/perf_event.h b/include/uapi/linux/perf_event.h
index 613ed9a..d97f84c 100644
--- a/include/uapi/linux/perf_event.h
+++ b/include/uapi/linux/perf_event.h
@@ -566,6 +566,10 @@ struct perf_event_mmap_page {
#define PERF_RECORD_MISC_GUEST_USER (5 << 0)
/*
+ * Indicates that /proc/PID/maps parsing are truncated by time out.
+ */
+#define PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT (1 << 12)
+/*
* PERF_RECORD_MISC_MMAP_DATA and PERF_RECORD_MISC_COMM_EXEC are used on
* different events so can reuse the same bit position.
*/
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 793b150..416ba80 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -213,6 +213,8 @@ static int perf_event__synthesize_fork(struct perf_tool *tool,
return 0;
}
+#define PROC_MAP_PARSE_TIMEOUT (500 * 1000000ULL)
+
int perf_event__synthesize_mmap_events(struct perf_tool *tool,
union perf_event *event,
pid_t pid, pid_t tgid,
@@ -222,6 +224,8 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
{
char filename[PATH_MAX];
FILE *fp;
+ unsigned long long t;
+ bool truncation = false;
int rc = 0;
if (machine__is_default_guest(machine))
@@ -240,6 +244,7 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
}
event->header.type = PERF_RECORD_MMAP2;
+ t = rdclock();
while (1) {
char bf[BUFSIZ];
@@ -253,6 +258,12 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
if (fgets(bf, sizeof(bf), fp) == NULL)
break;
+ if ((rdclock() - t) > PROC_MAP_PARSE_TIMEOUT) {
+ pr_warning("Reading %s time out.\n", filename);
+ truncation = true;
+ goto out;
+ }
+
/* ensure null termination since stack will be reused. */
strcpy(execname, "");
@@ -301,6 +312,10 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
event->header.misc |= PERF_RECORD_MISC_MMAP_DATA;
}
+out:
+ if (truncation)
+ event->header.misc |= PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT;
+
if (!strcmp(execname, ""))
strcpy(execname, anonstr);
@@ -319,6 +334,9 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
rc = -1;
break;
}
+
+ if (truncation)
+ break;
}
fclose(fp);
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 5dc51ad..39868f5 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -265,6 +265,7 @@ struct events_stats {
u32 nr_unknown_id;
u32 nr_unprocessable_samples;
u32 nr_auxtrace_errors[PERF_AUXTRACE_ERROR_MAX];
+ u32 nr_proc_map_timeout;
};
struct attr_event {
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 88d87bf..6968539 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1041,6 +1041,8 @@ static int machines__deliver_event(struct machines *machines,
case PERF_RECORD_MMAP:
return tool->mmap(tool, event, sample, machine);
case PERF_RECORD_MMAP2:
+ if (event->header.misc & PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT)
+ ++evlist->stats.nr_proc_map_timeout;
return tool->mmap2(tool, event, sample, machine);
case PERF_RECORD_COMM:
return tool->comm(tool, event, sample, machine);
@@ -1337,6 +1339,15 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
ui__warning("%u out of order events recorded.\n", oe->nr_unordered_events);
events_stats__auxtrace_error_warn(stats);
+
+ if (stats->nr_proc_map_timeout != 0) {
+ ui__warning("%d map information files for pre-existing threads were\n"
+ "not processed, if there are samples for addresses they\n"
+ "will not be resolved, you may find out which are these\n"
+ "threads by running with -v and redirecting the output\n"
+ "to a file.\n",
+ stats->nr_proc_map_timeout);
+ }
}
volatile int session_done;
--
1.8.3.1
From: Kan Liang <[email protected]>
The time out to limit the individual proc map processing was hard code
to 500ms. This patch introduce a new option --proc-map-timeout to make
the time limit configurable.
Signed-off-by: Kan Liang <[email protected]>
---
tools/perf/Documentation/perf-kvm.txt | 6 ++++++
tools/perf/Documentation/perf-record.txt | 5 +++++
tools/perf/Documentation/perf-top.txt | 6 ++++++
tools/perf/Documentation/perf-trace.txt | 5 +++++
tools/perf/builtin-kvm.c | 5 ++++-
tools/perf/builtin-record.c | 6 +++++-
tools/perf/builtin-top.c | 5 ++++-
tools/perf/builtin-trace.c | 6 +++++-
tools/perf/perf.h | 1 +
tools/perf/tests/code-reading.c | 2 +-
tools/perf/tests/dwarf-unwind.c | 2 +-
tools/perf/tests/mmap-thread-lookup.c | 4 ++--
tools/perf/util/event.c | 36 ++++++++++++++++++++------------
tools/perf/util/event.h | 9 +++++---
tools/perf/util/machine.c | 7 ++++---
tools/perf/util/machine.h | 9 +++++---
tools/perf/util/session.c | 4 +++-
17 files changed, 87 insertions(+), 31 deletions(-)
diff --git a/tools/perf/Documentation/perf-kvm.txt b/tools/perf/Documentation/perf-kvm.txt
index 6252e77..6a5bb2b 100644
--- a/tools/perf/Documentation/perf-kvm.txt
+++ b/tools/perf/Documentation/perf-kvm.txt
@@ -151,6 +151,12 @@ STAT LIVE OPTIONS
Show events other than HLT (x86 only) or Wait state (s390 only)
that take longer than duration usecs.
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take
+ a long time, because the file may be huge. A time out is needed
+ in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
SEE ALSO
--------
linkperf:perf-top[1], linkperf:perf-record[1], linkperf:perf-report[1],
diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index 280533e..8f3f6ce 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -267,6 +267,11 @@ AUX area tracing event. Optionally the number of bytes to capture per
snapshot can be specified. In Snapshot Mode, trace data is captured only when
signal SIGUSR2 is received.
+--proc-map-timeout::
+When processing pre-existing threads /proc/XXX/mmap, it may take a long time,
+because the file may be huge. A time out is needed in such cases.
+This option sets the time out limit. The default value is 500 ms.
+
SEE ALSO
--------
linkperf:perf-stat[1], linkperf:perf-list[1]
diff --git a/tools/perf/Documentation/perf-top.txt b/tools/perf/Documentation/perf-top.txt
index 9e5b07eb..776aec4 100644
--- a/tools/perf/Documentation/perf-top.txt
+++ b/tools/perf/Documentation/perf-top.txt
@@ -201,6 +201,12 @@ Default is to monitor all CPUS.
Force each column width to the provided list, for large terminal
readability. 0 means no limit (default behavior).
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take
+ a long time, because the file may be huge. A time out is needed
+ in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
INTERACTIVE PROMPTING KEYS
--------------------------
diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt
index 1db9c8b..7ea0786 100644
--- a/tools/perf/Documentation/perf-trace.txt
+++ b/tools/perf/Documentation/perf-trace.txt
@@ -121,6 +121,11 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs.
--event::
Trace other events, see 'perf list' for a complete list.
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take a long time,
+ because the file may be huge. A time out is needed in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
PAGEFAULTS
----------
diff --git a/tools/perf/builtin-kvm.c b/tools/perf/builtin-kvm.c
index 15fecd3..74878cd 100644
--- a/tools/perf/builtin-kvm.c
+++ b/tools/perf/builtin-kvm.c
@@ -1311,6 +1311,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
"show events other than"
" HLT (x86 only) or Wait state (s390 only)"
" that take longer than duration usecs"),
+ OPT_UINTEGER(0, "proc-map-timeout", &kvm->opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const live_usage[] = {
@@ -1338,6 +1340,7 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
kvm->opts.target.uses_mmap = false;
kvm->opts.target.uid_str = NULL;
kvm->opts.target.uid = UINT_MAX;
+ kvm->opts.proc_map_timeout = 500;
symbol__init(NULL);
disable_buildid_cache();
@@ -1393,7 +1396,7 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
perf_session__set_id_hdr_size(kvm->session);
ordered_events__set_copy_on_queue(&kvm->session->ordered_events, true);
machine__synthesize_threads(&kvm->session->machines.host, &kvm->opts.target,
- kvm->evlist->threads, false);
+ kvm->evlist->threads, false, kvm->opts.proc_map_timeout);
err = kvm_live_open_events(kvm);
if (err)
goto out;
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index d3731cc..0ae366d 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -598,7 +598,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
}
err = __machine__synthesize_threads(machine, tool, &opts->target, rec->evlist->threads,
- process_synthesized_event, opts->sample_address);
+ process_synthesized_event, opts->sample_address,
+ opts->proc_map_timeout);
if (err != 0)
goto out_child;
@@ -959,6 +960,7 @@ static struct record record = {
.uses_mmap = true,
.default_per_cpu = true,
},
+ .proc_map_timeout = 500,
},
.tool = {
.sample = process_sample_event,
@@ -1067,6 +1069,8 @@ struct option __record_options[] = {
parse_clockid),
OPT_STRING_OPTARG('S', "snapshot", &record.opts.auxtrace_snapshot_opts,
"opts", "AUX area tracing Snapshot Mode", ""),
+ OPT_UINTEGER(0, "proc-map-timeout", &record.opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index 6b98742..5cfc3aa 100644
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -951,7 +951,7 @@ static int __cmd_top(struct perf_top *top)
goto out_delete;
machine__synthesize_threads(&top->session->machines.host, &opts->target,
- top->evlist->threads, false);
+ top->evlist->threads, false, opts->proc_map_timeout);
ret = perf_top__start_counters(top);
if (ret)
goto out_delete;
@@ -1061,6 +1061,7 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
.target = {
.uses_mmap = true,
},
+ .proc_map_timeout = 500,
},
.max_stack = PERF_MAX_STACK_DEPTH,
.sym_pcnt_filter = 5,
@@ -1160,6 +1161,8 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
OPT_STRING('w', "column-widths", &symbol_conf.col_width_list_str,
"width[,width...]",
"don't try to adjust column width, use these fixed values"),
+ OPT_UINTEGER(0, "proc-map-timeout", &opts->proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const top_usage[] = {
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index a05490d..b022a95 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1460,7 +1460,8 @@ static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
return -ENOMEM;
err = __machine__synthesize_threads(trace->host, &trace->tool, &trace->opts.target,
- evlist->threads, trace__tool_process, false);
+ evlist->threads, trace__tool_process, false,
+ trace->opts.proc_map_timeout);
if (err)
symbol__exit();
@@ -2689,6 +2690,7 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
.user_interval = ULLONG_MAX,
.no_buffering = true,
.mmap_pages = UINT_MAX,
+ .proc_map_timeout = 500,
},
.output = stdout,
.show_comm = true,
@@ -2738,6 +2740,8 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
"Trace pagefaults", parse_pagefaults, "maj"),
OPT_BOOLEAN(0, "syscalls", &trace.trace_syscalls, "Trace syscalls"),
OPT_BOOLEAN('f', "force", &trace.force, "don't complain, do it"),
+ OPT_UINTEGER(0, "proc-map-timeout", &trace.opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const trace_subcommands[] = { "record", NULL };
diff --git a/tools/perf/perf.h b/tools/perf/perf.h
index aa79fb8..4a5827ff 100644
--- a/tools/perf/perf.h
+++ b/tools/perf/perf.h
@@ -69,6 +69,7 @@ struct record_opts {
unsigned initial_delay;
bool use_clockid;
clockid_t clockid;
+ unsigned int proc_map_timeout;
};
struct option;
diff --git a/tools/perf/tests/code-reading.c b/tools/perf/tests/code-reading.c
index e2a432b..22f8a00 100644
--- a/tools/perf/tests/code-reading.c
+++ b/tools/perf/tests/code-reading.c
@@ -451,7 +451,7 @@ static int do_test_code_reading(bool try_kcore)
}
ret = perf_event__synthesize_thread_map(NULL, threads,
- perf_event__process, machine, false);
+ perf_event__process, machine, false, 500);
if (ret < 0) {
pr_debug("perf_event__synthesize_thread_map failed\n");
goto out_err;
diff --git a/tools/perf/tests/dwarf-unwind.c b/tools/perf/tests/dwarf-unwind.c
index 9b748e1..40b36c4 100644
--- a/tools/perf/tests/dwarf-unwind.c
+++ b/tools/perf/tests/dwarf-unwind.c
@@ -28,7 +28,7 @@ static int init_live_machine(struct machine *machine)
pid_t pid = getpid();
return perf_event__synthesize_mmap_events(NULL, &event, pid, pid,
- mmap_handler, machine, true);
+ mmap_handler, machine, true, 500);
}
#define MAX_STACK 8
diff --git a/tools/perf/tests/mmap-thread-lookup.c b/tools/perf/tests/mmap-thread-lookup.c
index 264e215..7f48efa 100644
--- a/tools/perf/tests/mmap-thread-lookup.c
+++ b/tools/perf/tests/mmap-thread-lookup.c
@@ -129,7 +129,7 @@ static int synth_all(struct machine *machine)
{
return perf_event__synthesize_threads(NULL,
perf_event__process,
- machine, 0);
+ machine, 0, 500);
}
static int synth_process(struct machine *machine)
@@ -141,7 +141,7 @@ static int synth_process(struct machine *machine)
err = perf_event__synthesize_thread_map(NULL, map,
perf_event__process,
- machine, 0);
+ machine, 0, 500);
thread_map__delete(map);
return err;
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 416ba80..d7d986d 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -213,19 +213,19 @@ static int perf_event__synthesize_fork(struct perf_tool *tool,
return 0;
}
-#define PROC_MAP_PARSE_TIMEOUT (500 * 1000000ULL)
-
int perf_event__synthesize_mmap_events(struct perf_tool *tool,
union perf_event *event,
pid_t pid, pid_t tgid,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data)
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
char filename[PATH_MAX];
FILE *fp;
unsigned long long t;
bool truncation = false;
+ unsigned long long timeout = proc_map_timeout * 1000000ULL;
int rc = 0;
if (machine__is_default_guest(machine))
@@ -258,8 +258,11 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
if (fgets(bf, sizeof(bf), fp) == NULL)
break;
- if ((rdclock() - t) > PROC_MAP_PARSE_TIMEOUT) {
- pr_warning("Reading %s time out.\n", filename);
+ if ((rdclock() - t) > timeout) {
+ pr_warning("Reading %s time out. "
+ "You may want to increase "
+ "the time limit by --proc-map-timeout\n",
+ filename);
truncation = true;
goto out;
}
@@ -404,7 +407,9 @@ static int __event__synthesize_thread(union perf_event *comm_event,
pid_t pid, int full,
perf_event__handler_t process,
struct perf_tool *tool,
- struct machine *machine, bool mmap_data)
+ struct machine *machine,
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
char filename[PATH_MAX];
DIR *tasks;
@@ -421,7 +426,8 @@ static int __event__synthesize_thread(union perf_event *comm_event,
return -1;
return perf_event__synthesize_mmap_events(tool, mmap_event, pid, tgid,
- process, machine, mmap_data);
+ process, machine, mmap_data,
+ proc_map_timeout);
}
if (machine__is_default_guest(machine))
@@ -462,7 +468,7 @@ static int __event__synthesize_thread(union perf_event *comm_event,
if (_pid == pid) {
/* process the parent's maps too */
rc = perf_event__synthesize_mmap_events(tool, mmap_event, pid, tgid,
- process, machine, mmap_data);
+ process, machine, mmap_data, proc_map_timeout);
if (rc)
break;
}
@@ -476,7 +482,8 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
struct thread_map *threads,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data)
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
union perf_event *comm_event, *mmap_event, *fork_event;
int err = -1, thread, j;
@@ -499,7 +506,7 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
fork_event,
threads->map[thread], 0,
process, tool, machine,
- mmap_data)) {
+ mmap_data, proc_map_timeout)) {
err = -1;
break;
}
@@ -525,7 +532,7 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
fork_event,
comm_event->comm.pid, 0,
process, tool, machine,
- mmap_data)) {
+ mmap_data, proc_map_timeout)) {
err = -1;
break;
}
@@ -542,7 +549,9 @@ out:
int perf_event__synthesize_threads(struct perf_tool *tool,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data)
+ struct machine *machine,
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
DIR *proc;
char proc_path[PATH_MAX];
@@ -582,7 +591,8 @@ int perf_event__synthesize_threads(struct perf_tool *tool,
* one thread couldn't be synthesized.
*/
__event__synthesize_thread(comm_event, mmap_event, fork_event, pid,
- 1, process, tool, machine, mmap_data);
+ 1, process, tool, machine, mmap_data,
+ proc_map_timeout);
}
err = 0;
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 39868f5..c53f363 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -384,10 +384,12 @@ typedef int (*perf_event__handler_t)(struct perf_tool *tool,
int perf_event__synthesize_thread_map(struct perf_tool *tool,
struct thread_map *threads,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data);
+ struct machine *machine, bool mmap_data,
+ unsigned int proc_map_timeout);
int perf_event__synthesize_threads(struct perf_tool *tool,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data);
+ struct machine *machine, bool mmap_data,
+ unsigned int proc_map_timeout);
int perf_event__synthesize_kernel_mmap(struct perf_tool *tool,
perf_event__handler_t process,
struct machine *machine);
@@ -469,7 +471,8 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
pid_t pid, pid_t tgid,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data);
+ bool mmap_data,
+ unsigned int proc_map_timeout);
size_t perf_event__fprintf_comm(union perf_event *event, FILE *fp);
size_t perf_event__fprintf_mmap(union perf_event *event, FILE *fp);
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 132e357..968cea8 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1892,12 +1892,13 @@ int machine__for_each_thread(struct machine *machine,
int __machine__synthesize_threads(struct machine *machine, struct perf_tool *tool,
struct target *target, struct thread_map *threads,
- perf_event__handler_t process, bool data_mmap)
+ perf_event__handler_t process, bool data_mmap,
+ unsigned int proc_map_timeout)
{
if (target__has_task(target))
- return perf_event__synthesize_thread_map(tool, threads, process, machine, data_mmap);
+ return perf_event__synthesize_thread_map(tool, threads, process, machine, data_mmap, proc_map_timeout);
else if (target__has_cpu(target))
- return perf_event__synthesize_threads(tool, process, machine, data_mmap);
+ return perf_event__synthesize_threads(tool, process, machine, data_mmap, proc_map_timeout);
/* command specified */
return 0;
}
diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
index ca267c4..4333a3a 100644
--- a/tools/perf/util/machine.h
+++ b/tools/perf/util/machine.h
@@ -219,13 +219,16 @@ int machine__for_each_thread(struct machine *machine,
int __machine__synthesize_threads(struct machine *machine, struct perf_tool *tool,
struct target *target, struct thread_map *threads,
- perf_event__handler_t process, bool data_mmap);
+ perf_event__handler_t process, bool data_mmap,
+ unsigned int proc_map_timeout);
static inline
int machine__synthesize_threads(struct machine *machine, struct target *target,
- struct thread_map *threads, bool data_mmap)
+ struct thread_map *threads, bool data_mmap,
+ unsigned int proc_map_timeout)
{
return __machine__synthesize_threads(machine, NULL, target, threads,
- perf_event__process, data_mmap);
+ perf_event__process, data_mmap,
+ proc_map_timeout);
}
pid_t machine__get_current_tid(struct machine *machine, int cpu);
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 6968539..06e5d84 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1345,7 +1345,9 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
"not processed, if there are samples for addresses they\n"
"will not be resolved, you may find out which are these\n"
"threads by running with -v and redirecting the output\n"
- "to a file.\n",
+ "to a file.\n"
+ "The time limit to process proc map is too short?\n"
+ "Increase it by --proc-map-timeout\n",
stats->nr_proc_map_timeout);
}
}
--
1.8.3.1
Em Wed, Jun 17, 2015 at 09:51:10AM -0400, [email protected] escreveu:
> From: Kan Liang <[email protected]>
> System wide sampling like 'perf top' or 'perf record -a' read all
> threads /proc/xxx/maps before sampling. If there are any threads which
> generating a keeping growing huge maps, perf will do infinite loop
> during synthesizing. Nothing will be sampled.
>
> This patch fixes this issue by adding per-thread timeout to force stop
> this kind of endless proc map processing.
> PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is introduced to indicate that
> the mmap record are truncated by time out. User will get warning
> notification when truncated mmap records are detected.
I am applying the patch, we indeed need to keep it in the
last PERF_RECORD_MMAP2 we synthesized for a proc mmap file, i.e. it
has to be stored in the perf.data file, so that later, at 'report' time,
possibly in another machine, that situation can be reported to the user.
But, the warning is only being showm for tools that process events via
perf_session__process_events(), like 'perf report'.
'top' and 'trace', for instance, don't do that, so the users will not
be warned in that case.
To fix this we need to make machine__process_mmap2_event() notice that
PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is set, and bump a per-struct
machine counter, something like machine->stats.nr_truncated_mmaps.
The callchain is:
builtin-top.c
machine__synthesize_threads()
__machine__synthesize_threads()
perf_event__process()
machine__process_event()
machine__process_mmap2_event()
At some point even a event_stats may make sense to be added to struct
machine :-)
- Arnaldo
Commit-ID: 930e6fcd2bcce9bcd9d4aa7e755678d33f3fe6f4
Gitweb: http://git.kernel.org/tip/930e6fcd2bcce9bcd9d4aa7e755678d33f3fe6f4
Author: Kan Liang <[email protected]>
AuthorDate: Wed, 17 Jun 2015 09:51:10 -0400
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Fri, 19 Jun 2015 18:20:15 -0300
perf tools: Add time out to force stop proc map processing
System wide sampling like 'perf top' or 'perf record -a' read all
threads /proc/xxx/maps before sampling. If there are any threads which
generating a keeping growing huge maps, perf will do infinite loop
during synthesizing. Nothing will be sampled.
This patch fixes this issue by adding per-thread timeout to force stop
this kind of endless proc map processing.
PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is introduced to indicate that
the mmap record are truncated by time out. User will get warning
notification when truncated mmap records are detected.
Reported-by: Ying Huang <[email protected]>
Signed-off-by: Kan Liang <[email protected]>
Cc: Andi Kleen <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Ying Huang <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
include/uapi/linux/perf_event.h | 4 ++++
tools/perf/util/event.c | 18 ++++++++++++++++++
tools/perf/util/event.h | 1 +
tools/perf/util/session.c | 11 +++++++++++
4 files changed, 34 insertions(+)
diff --git a/include/uapi/linux/perf_event.h b/include/uapi/linux/perf_event.h
index 613ed9a..d97f84c 100644
--- a/include/uapi/linux/perf_event.h
+++ b/include/uapi/linux/perf_event.h
@@ -566,6 +566,10 @@ struct perf_event_mmap_page {
#define PERF_RECORD_MISC_GUEST_USER (5 << 0)
/*
+ * Indicates that /proc/PID/maps parsing are truncated by time out.
+ */
+#define PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT (1 << 12)
+/*
* PERF_RECORD_MISC_MMAP_DATA and PERF_RECORD_MISC_COMM_EXEC are used on
* different events so can reuse the same bit position.
*/
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 793b150..416ba80 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -213,6 +213,8 @@ static int perf_event__synthesize_fork(struct perf_tool *tool,
return 0;
}
+#define PROC_MAP_PARSE_TIMEOUT (500 * 1000000ULL)
+
int perf_event__synthesize_mmap_events(struct perf_tool *tool,
union perf_event *event,
pid_t pid, pid_t tgid,
@@ -222,6 +224,8 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
{
char filename[PATH_MAX];
FILE *fp;
+ unsigned long long t;
+ bool truncation = false;
int rc = 0;
if (machine__is_default_guest(machine))
@@ -240,6 +244,7 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
}
event->header.type = PERF_RECORD_MMAP2;
+ t = rdclock();
while (1) {
char bf[BUFSIZ];
@@ -253,6 +258,12 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
if (fgets(bf, sizeof(bf), fp) == NULL)
break;
+ if ((rdclock() - t) > PROC_MAP_PARSE_TIMEOUT) {
+ pr_warning("Reading %s time out.\n", filename);
+ truncation = true;
+ goto out;
+ }
+
/* ensure null termination since stack will be reused. */
strcpy(execname, "");
@@ -301,6 +312,10 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
event->header.misc |= PERF_RECORD_MISC_MMAP_DATA;
}
+out:
+ if (truncation)
+ event->header.misc |= PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT;
+
if (!strcmp(execname, ""))
strcpy(execname, anonstr);
@@ -319,6 +334,9 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
rc = -1;
break;
}
+
+ if (truncation)
+ break;
}
fclose(fp);
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 5dc51ad..39868f5 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -265,6 +265,7 @@ struct events_stats {
u32 nr_unknown_id;
u32 nr_unprocessable_samples;
u32 nr_auxtrace_errors[PERF_AUXTRACE_ERROR_MAX];
+ u32 nr_proc_map_timeout;
};
struct attr_event {
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index c371336..2d882fd 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1064,6 +1064,8 @@ static int machines__deliver_event(struct machines *machines,
case PERF_RECORD_MMAP:
return tool->mmap(tool, event, sample, machine);
case PERF_RECORD_MMAP2:
+ if (event->header.misc & PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT)
+ ++evlist->stats.nr_proc_map_timeout;
return tool->mmap2(tool, event, sample, machine);
case PERF_RECORD_COMM:
return tool->comm(tool, event, sample, machine);
@@ -1360,6 +1362,15 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
ui__warning("%u out of order events recorded.\n", oe->nr_unordered_events);
events_stats__auxtrace_error_warn(stats);
+
+ if (stats->nr_proc_map_timeout != 0) {
+ ui__warning("%d map information files for pre-existing threads were\n"
+ "not processed, if there are samples for addresses they\n"
+ "will not be resolved, you may find out which are these\n"
+ "threads by running with -v and redirecting the output\n"
+ "to a file.\n",
+ stats->nr_proc_map_timeout);
+ }
}
static int perf_session__flush_thread_stack(struct thread *thread,
Commit-ID: 9d9cad763ca79dd3697e9f2d1df648e37496582b
Gitweb: http://git.kernel.org/tip/9d9cad763ca79dd3697e9f2d1df648e37496582b
Author: Kan Liang <[email protected]>
AuthorDate: Wed, 17 Jun 2015 09:51:11 -0400
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Fri, 19 Jun 2015 18:27:13 -0300
perf tools: Configurable per thread proc map processing time out
The time out to limit the individual proc map processing was hard code
to 500ms. This patch introduce a new option --proc-map-timeout to make
the time limit configurable.
Signed-off-by: Kan Liang <[email protected]>
Cc: Andi Kleen <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Ying Huang <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/Documentation/perf-kvm.txt | 6 ++++++
tools/perf/Documentation/perf-record.txt | 5 +++++
tools/perf/Documentation/perf-top.txt | 6 ++++++
tools/perf/Documentation/perf-trace.txt | 5 +++++
tools/perf/builtin-kvm.c | 5 ++++-
tools/perf/builtin-record.c | 6 +++++-
tools/perf/builtin-top.c | 5 ++++-
tools/perf/builtin-trace.c | 6 +++++-
tools/perf/perf.h | 1 +
tools/perf/tests/code-reading.c | 2 +-
tools/perf/tests/dwarf-unwind.c | 2 +-
tools/perf/tests/mmap-thread-lookup.c | 4 ++--
tools/perf/util/event.c | 36 ++++++++++++++++++++------------
tools/perf/util/event.h | 9 +++++---
tools/perf/util/machine.c | 7 ++++---
tools/perf/util/machine.h | 9 +++++---
tools/perf/util/session.c | 4 +++-
17 files changed, 87 insertions(+), 31 deletions(-)
diff --git a/tools/perf/Documentation/perf-kvm.txt b/tools/perf/Documentation/perf-kvm.txt
index 6252e77..6a5bb2b 100644
--- a/tools/perf/Documentation/perf-kvm.txt
+++ b/tools/perf/Documentation/perf-kvm.txt
@@ -151,6 +151,12 @@ STAT LIVE OPTIONS
Show events other than HLT (x86 only) or Wait state (s390 only)
that take longer than duration usecs.
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take
+ a long time, because the file may be huge. A time out is needed
+ in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
SEE ALSO
--------
linkperf:perf-top[1], linkperf:perf-record[1], linkperf:perf-report[1],
diff --git a/tools/perf/Documentation/perf-record.txt b/tools/perf/Documentation/perf-record.txt
index 6fdf786..9b9d9d0 100644
--- a/tools/perf/Documentation/perf-record.txt
+++ b/tools/perf/Documentation/perf-record.txt
@@ -271,6 +271,11 @@ AUX area tracing event. Optionally the number of bytes to capture per
snapshot can be specified. In Snapshot Mode, trace data is captured only when
signal SIGUSR2 is received.
+--proc-map-timeout::
+When processing pre-existing threads /proc/XXX/mmap, it may take a long time,
+because the file may be huge. A time out is needed in such cases.
+This option sets the time out limit. The default value is 500 ms.
+
SEE ALSO
--------
linkperf:perf-stat[1], linkperf:perf-list[1]
diff --git a/tools/perf/Documentation/perf-top.txt b/tools/perf/Documentation/perf-top.txt
index 9e5b07eb..776aec4 100644
--- a/tools/perf/Documentation/perf-top.txt
+++ b/tools/perf/Documentation/perf-top.txt
@@ -201,6 +201,12 @@ Default is to monitor all CPUS.
Force each column width to the provided list, for large terminal
readability. 0 means no limit (default behavior).
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take
+ a long time, because the file may be huge. A time out is needed
+ in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
INTERACTIVE PROMPTING KEYS
--------------------------
diff --git a/tools/perf/Documentation/perf-trace.txt b/tools/perf/Documentation/perf-trace.txt
index 1db9c8b..7ea0786 100644
--- a/tools/perf/Documentation/perf-trace.txt
+++ b/tools/perf/Documentation/perf-trace.txt
@@ -121,6 +121,11 @@ the thread executes on the designated CPUs. Default is to monitor all CPUs.
--event::
Trace other events, see 'perf list' for a complete list.
+--proc-map-timeout::
+ When processing pre-existing threads /proc/XXX/mmap, it may take a long time,
+ because the file may be huge. A time out is needed in such cases.
+ This option sets the time out limit. The default value is 500 ms.
+
PAGEFAULTS
----------
diff --git a/tools/perf/builtin-kvm.c b/tools/perf/builtin-kvm.c
index 15fecd3..74878cd 100644
--- a/tools/perf/builtin-kvm.c
+++ b/tools/perf/builtin-kvm.c
@@ -1311,6 +1311,8 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
"show events other than"
" HLT (x86 only) or Wait state (s390 only)"
" that take longer than duration usecs"),
+ OPT_UINTEGER(0, "proc-map-timeout", &kvm->opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const live_usage[] = {
@@ -1338,6 +1340,7 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
kvm->opts.target.uses_mmap = false;
kvm->opts.target.uid_str = NULL;
kvm->opts.target.uid = UINT_MAX;
+ kvm->opts.proc_map_timeout = 500;
symbol__init(NULL);
disable_buildid_cache();
@@ -1393,7 +1396,7 @@ static int kvm_events_live(struct perf_kvm_stat *kvm,
perf_session__set_id_hdr_size(kvm->session);
ordered_events__set_copy_on_queue(&kvm->session->ordered_events, true);
machine__synthesize_threads(&kvm->session->machines.host, &kvm->opts.target,
- kvm->evlist->threads, false);
+ kvm->evlist->threads, false, kvm->opts.proc_map_timeout);
err = kvm_live_open_events(kvm);
if (err)
goto out;
diff --git a/tools/perf/builtin-record.c b/tools/perf/builtin-record.c
index 4d6cdeb..de165a1 100644
--- a/tools/perf/builtin-record.c
+++ b/tools/perf/builtin-record.c
@@ -598,7 +598,8 @@ static int __cmd_record(struct record *rec, int argc, const char **argv)
}
err = __machine__synthesize_threads(machine, tool, &opts->target, rec->evlist->threads,
- process_synthesized_event, opts->sample_address);
+ process_synthesized_event, opts->sample_address,
+ opts->proc_map_timeout);
if (err != 0)
goto out_child;
@@ -959,6 +960,7 @@ static struct record record = {
.uses_mmap = true,
.default_per_cpu = true,
},
+ .proc_map_timeout = 500,
},
.tool = {
.sample = process_sample_event,
@@ -1066,6 +1068,8 @@ struct option __record_options[] = {
parse_clockid),
OPT_STRING_OPTARG('S', "snapshot", &record.opts.auxtrace_snapshot_opts,
"opts", "AUX area tracing Snapshot Mode", ""),
+ OPT_UINTEGER(0, "proc-map-timeout", &record.opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index 70a9505..619a869 100644
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -977,7 +977,7 @@ static int __cmd_top(struct perf_top *top)
goto out_delete;
machine__synthesize_threads(&top->session->machines.host, &opts->target,
- top->evlist->threads, false);
+ top->evlist->threads, false, opts->proc_map_timeout);
ret = perf_top__start_counters(top);
if (ret)
goto out_delete;
@@ -1087,6 +1087,7 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
.target = {
.uses_mmap = true,
},
+ .proc_map_timeout = 500,
},
.max_stack = PERF_MAX_STACK_DEPTH,
.sym_pcnt_filter = 5,
@@ -1186,6 +1187,8 @@ int cmd_top(int argc, const char **argv, const char *prefix __maybe_unused)
OPT_STRING('w', "column-widths", &symbol_conf.col_width_list_str,
"width[,width...]",
"don't try to adjust column width, use these fixed values"),
+ OPT_UINTEGER(0, "proc-map-timeout", &opts->proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const top_usage[] = {
diff --git a/tools/perf/builtin-trace.c b/tools/perf/builtin-trace.c
index 4bf805b..de5d277 100644
--- a/tools/perf/builtin-trace.c
+++ b/tools/perf/builtin-trace.c
@@ -1518,7 +1518,8 @@ static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
return -ENOMEM;
err = __machine__synthesize_threads(trace->host, &trace->tool, &trace->opts.target,
- evlist->threads, trace__tool_process, false);
+ evlist->threads, trace__tool_process, false,
+ trace->opts.proc_map_timeout);
if (err)
symbol__exit();
@@ -2747,6 +2748,7 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
.user_interval = ULLONG_MAX,
.no_buffering = true,
.mmap_pages = UINT_MAX,
+ .proc_map_timeout = 500,
},
.output = stdout,
.show_comm = true,
@@ -2796,6 +2798,8 @@ int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
"Trace pagefaults", parse_pagefaults, "maj"),
OPT_BOOLEAN(0, "syscalls", &trace.trace_syscalls, "Trace syscalls"),
OPT_BOOLEAN('f', "force", &trace.force, "don't complain, do it"),
+ OPT_UINTEGER(0, "proc-map-timeout", &trace.opts.proc_map_timeout,
+ "per thread proc mmap processing timeout in ms"),
OPT_END()
};
const char * const trace_subcommands[] = { "record", NULL };
diff --git a/tools/perf/perf.h b/tools/perf/perf.h
index aa79fb8..4a5827ff 100644
--- a/tools/perf/perf.h
+++ b/tools/perf/perf.h
@@ -69,6 +69,7 @@ struct record_opts {
unsigned initial_delay;
bool use_clockid;
clockid_t clockid;
+ unsigned int proc_map_timeout;
};
struct option;
diff --git a/tools/perf/tests/code-reading.c b/tools/perf/tests/code-reading.c
index e2a432b..22f8a00 100644
--- a/tools/perf/tests/code-reading.c
+++ b/tools/perf/tests/code-reading.c
@@ -451,7 +451,7 @@ static int do_test_code_reading(bool try_kcore)
}
ret = perf_event__synthesize_thread_map(NULL, threads,
- perf_event__process, machine, false);
+ perf_event__process, machine, false, 500);
if (ret < 0) {
pr_debug("perf_event__synthesize_thread_map failed\n");
goto out_err;
diff --git a/tools/perf/tests/dwarf-unwind.c b/tools/perf/tests/dwarf-unwind.c
index 9b748e1..40b36c4 100644
--- a/tools/perf/tests/dwarf-unwind.c
+++ b/tools/perf/tests/dwarf-unwind.c
@@ -28,7 +28,7 @@ static int init_live_machine(struct machine *machine)
pid_t pid = getpid();
return perf_event__synthesize_mmap_events(NULL, &event, pid, pid,
- mmap_handler, machine, true);
+ mmap_handler, machine, true, 500);
}
#define MAX_STACK 8
diff --git a/tools/perf/tests/mmap-thread-lookup.c b/tools/perf/tests/mmap-thread-lookup.c
index 264e215..7f48efa 100644
--- a/tools/perf/tests/mmap-thread-lookup.c
+++ b/tools/perf/tests/mmap-thread-lookup.c
@@ -129,7 +129,7 @@ static int synth_all(struct machine *machine)
{
return perf_event__synthesize_threads(NULL,
perf_event__process,
- machine, 0);
+ machine, 0, 500);
}
static int synth_process(struct machine *machine)
@@ -141,7 +141,7 @@ static int synth_process(struct machine *machine)
err = perf_event__synthesize_thread_map(NULL, map,
perf_event__process,
- machine, 0);
+ machine, 0, 500);
thread_map__delete(map);
return err;
diff --git a/tools/perf/util/event.c b/tools/perf/util/event.c
index 416ba80..d7d986d 100644
--- a/tools/perf/util/event.c
+++ b/tools/perf/util/event.c
@@ -213,19 +213,19 @@ static int perf_event__synthesize_fork(struct perf_tool *tool,
return 0;
}
-#define PROC_MAP_PARSE_TIMEOUT (500 * 1000000ULL)
-
int perf_event__synthesize_mmap_events(struct perf_tool *tool,
union perf_event *event,
pid_t pid, pid_t tgid,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data)
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
char filename[PATH_MAX];
FILE *fp;
unsigned long long t;
bool truncation = false;
+ unsigned long long timeout = proc_map_timeout * 1000000ULL;
int rc = 0;
if (machine__is_default_guest(machine))
@@ -258,8 +258,11 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
if (fgets(bf, sizeof(bf), fp) == NULL)
break;
- if ((rdclock() - t) > PROC_MAP_PARSE_TIMEOUT) {
- pr_warning("Reading %s time out.\n", filename);
+ if ((rdclock() - t) > timeout) {
+ pr_warning("Reading %s time out. "
+ "You may want to increase "
+ "the time limit by --proc-map-timeout\n",
+ filename);
truncation = true;
goto out;
}
@@ -404,7 +407,9 @@ static int __event__synthesize_thread(union perf_event *comm_event,
pid_t pid, int full,
perf_event__handler_t process,
struct perf_tool *tool,
- struct machine *machine, bool mmap_data)
+ struct machine *machine,
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
char filename[PATH_MAX];
DIR *tasks;
@@ -421,7 +426,8 @@ static int __event__synthesize_thread(union perf_event *comm_event,
return -1;
return perf_event__synthesize_mmap_events(tool, mmap_event, pid, tgid,
- process, machine, mmap_data);
+ process, machine, mmap_data,
+ proc_map_timeout);
}
if (machine__is_default_guest(machine))
@@ -462,7 +468,7 @@ static int __event__synthesize_thread(union perf_event *comm_event,
if (_pid == pid) {
/* process the parent's maps too */
rc = perf_event__synthesize_mmap_events(tool, mmap_event, pid, tgid,
- process, machine, mmap_data);
+ process, machine, mmap_data, proc_map_timeout);
if (rc)
break;
}
@@ -476,7 +482,8 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
struct thread_map *threads,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data)
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
union perf_event *comm_event, *mmap_event, *fork_event;
int err = -1, thread, j;
@@ -499,7 +506,7 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
fork_event,
threads->map[thread], 0,
process, tool, machine,
- mmap_data)) {
+ mmap_data, proc_map_timeout)) {
err = -1;
break;
}
@@ -525,7 +532,7 @@ int perf_event__synthesize_thread_map(struct perf_tool *tool,
fork_event,
comm_event->comm.pid, 0,
process, tool, machine,
- mmap_data)) {
+ mmap_data, proc_map_timeout)) {
err = -1;
break;
}
@@ -542,7 +549,9 @@ out:
int perf_event__synthesize_threads(struct perf_tool *tool,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data)
+ struct machine *machine,
+ bool mmap_data,
+ unsigned int proc_map_timeout)
{
DIR *proc;
char proc_path[PATH_MAX];
@@ -582,7 +591,8 @@ int perf_event__synthesize_threads(struct perf_tool *tool,
* one thread couldn't be synthesized.
*/
__event__synthesize_thread(comm_event, mmap_event, fork_event, pid,
- 1, process, tool, machine, mmap_data);
+ 1, process, tool, machine, mmap_data,
+ proc_map_timeout);
}
err = 0;
diff --git a/tools/perf/util/event.h b/tools/perf/util/event.h
index 39868f5..c53f363 100644
--- a/tools/perf/util/event.h
+++ b/tools/perf/util/event.h
@@ -384,10 +384,12 @@ typedef int (*perf_event__handler_t)(struct perf_tool *tool,
int perf_event__synthesize_thread_map(struct perf_tool *tool,
struct thread_map *threads,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data);
+ struct machine *machine, bool mmap_data,
+ unsigned int proc_map_timeout);
int perf_event__synthesize_threads(struct perf_tool *tool,
perf_event__handler_t process,
- struct machine *machine, bool mmap_data);
+ struct machine *machine, bool mmap_data,
+ unsigned int proc_map_timeout);
int perf_event__synthesize_kernel_mmap(struct perf_tool *tool,
perf_event__handler_t process,
struct machine *machine);
@@ -469,7 +471,8 @@ int perf_event__synthesize_mmap_events(struct perf_tool *tool,
pid_t pid, pid_t tgid,
perf_event__handler_t process,
struct machine *machine,
- bool mmap_data);
+ bool mmap_data,
+ unsigned int proc_map_timeout);
size_t perf_event__fprintf_comm(union perf_event *event, FILE *fp);
size_t perf_event__fprintf_mmap(union perf_event *event, FILE *fp);
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 8b3b193..4744673 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1913,12 +1913,13 @@ int machines__for_each_thread(struct machines *machines,
int __machine__synthesize_threads(struct machine *machine, struct perf_tool *tool,
struct target *target, struct thread_map *threads,
- perf_event__handler_t process, bool data_mmap)
+ perf_event__handler_t process, bool data_mmap,
+ unsigned int proc_map_timeout)
{
if (target__has_task(target))
- return perf_event__synthesize_thread_map(tool, threads, process, machine, data_mmap);
+ return perf_event__synthesize_thread_map(tool, threads, process, machine, data_mmap, proc_map_timeout);
else if (target__has_cpu(target))
- return perf_event__synthesize_threads(tool, process, machine, data_mmap);
+ return perf_event__synthesize_threads(tool, process, machine, data_mmap, proc_map_timeout);
/* command specified */
return 0;
}
diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
index cea62f6..887798e 100644
--- a/tools/perf/util/machine.h
+++ b/tools/perf/util/machine.h
@@ -222,13 +222,16 @@ int machines__for_each_thread(struct machines *machines,
int __machine__synthesize_threads(struct machine *machine, struct perf_tool *tool,
struct target *target, struct thread_map *threads,
- perf_event__handler_t process, bool data_mmap);
+ perf_event__handler_t process, bool data_mmap,
+ unsigned int proc_map_timeout);
static inline
int machine__synthesize_threads(struct machine *machine, struct target *target,
- struct thread_map *threads, bool data_mmap)
+ struct thread_map *threads, bool data_mmap,
+ unsigned int proc_map_timeout)
{
return __machine__synthesize_threads(machine, NULL, target, threads,
- perf_event__process, data_mmap);
+ perf_event__process, data_mmap,
+ proc_map_timeout);
}
pid_t machine__get_current_tid(struct machine *machine, int cpu);
diff --git a/tools/perf/util/session.c b/tools/perf/util/session.c
index 2d882fd..aa482c1 100644
--- a/tools/perf/util/session.c
+++ b/tools/perf/util/session.c
@@ -1368,7 +1368,9 @@ static void perf_session__warn_about_errors(const struct perf_session *session)
"not processed, if there are samples for addresses they\n"
"will not be resolved, you may find out which are these\n"
"threads by running with -v and redirecting the output\n"
- "to a file.\n",
+ "to a file.\n"
+ "The time limit to process proc map is too short?\n"
+ "Increase it by --proc-map-timeout\n",
stats->nr_proc_map_timeout);
}
}
> Em Wed, Jun 17, 2015 at 09:51:10AM -0400, [email protected] escreveu:
> > From: Kan Liang <[email protected]>
> > System wide sampling like 'perf top' or 'perf record -a' read all
> > threads /proc/xxx/maps before sampling. If there are any threads which
> > generating a keeping growing huge maps, perf will do infinite loop
> > during synthesizing. Nothing will be sampled.
> >
> > This patch fixes this issue by adding per-thread timeout to force stop
> > this kind of endless proc map processing.
> > PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is introduced to
> indicate
> > that the mmap record are truncated by time out. User will get warning
> > notification when truncated mmap records are detected.
>
> I am applying the patch, we indeed need to keep it in the last
> PERF_RECORD_MMAP2 we synthesized for a proc mmap file, i.e. it has to
> be stored in the perf.data file, so that later, at 'report' time, possibly in
> another machine, that situation can be reported to the user.
>
> But, the warning is only being showm for tools that process events via
> perf_session__process_events(), like 'perf report'.
>
> 'top' and 'trace', for instance, don't do that, so the users will not be warned
> in that case.
The users can be warned right away by pr_warning when time out is detected.
I tested both 'top' and 'trace'.
# perf trace
Reading /proc/18099/maps time out. You may want to increase the time limit
by --proc-map-timeout
Reading /proc/18100/maps time out. You may want to increase the time limit
by --proc-map-timeout
For 'top', the error message will be printed at the bottom of the screen.
The user may not notice it with default --tui mode, only if there is very small
number of threads time out. (My test case has 64 threads time out. The error
messages last 32 seconds, the user must notice that.)
So the problem is only for some case of 'top'.
>
> To fix this we need to make machine__process_mmap2_event() notice
> that PERF_RECORD_MISC_PROC_MAP_PARSE_TIME_OUT is set, and
> bump a per-struct machine counter, something like machine-
> >stats.nr_truncated_mmaps.
machine__process_mmap2_event also be called by 'record', 'report', etc.
Since it's an issue only for 'top'.
How about update nr_truncated_mmaps in machine__process_event?
diff --git a/tools/perf/builtin-top.c b/tools/perf/builtin-top.c
index 5cfc3aa..95a1dc5 100644
--- a/tools/perf/builtin-top.c
+++ b/tools/perf/builtin-top.c
@@ -952,6 +952,16 @@ static int __cmd_top(struct perf_top *top)
machine__synthesize_threads(&top->session->machines.host, &opts->target,
top->evlist->threads, false, opts->proc_map_timeout);
+
+ if (top->session->machines.host.nr_truncated_mmaps)
+ ui__warning("%d map information files for pre-existing threads were\n"
+ "not processed, if there are samples for addresses they\n"
+ "will not be resolved, you may find out which are these\n"
+ "threads by running with --stdio\n"
+ "The time limit to process proc map is too short?\n"
+ "Increase it by --proc-map-timeout\n",
+ top->session->machines.host.nr_truncated_mmaps);
+
ret = perf_top__start_counters(top);
if (ret)
goto out_delete;
diff --git a/tools/perf/util/machine.c b/tools/perf/util/machine.c
index 968cea8..7d960ff 100644
--- a/tools/perf/util/machine.c
+++ b/tools/perf/util/machine.c
@@ -1438,6 +1438,8 @@ int machine__process_event(struct machine *machine, union perf_event *event,
case PERF_RECORD_MMAP:
ret = machine__process_mmap_event(machine, event, sample); break;
case PERF_RECORD_MMAP2:
+ if (event->header.misc & PERF_RECORD_MISC_PROC_MAP_PARSE_TIMEOUT)
+ machine->nr_truncated_mmaps++;
ret = machine__process_mmap2_event(machine, event, sample); break;
case PERF_RECORD_FORK:
ret = machine__process_fork_event(machine, event, sample); break;
diff --git a/tools/perf/util/machine.h b/tools/perf/util/machine.h
index 4333a3a..af74955 100644
--- a/tools/perf/util/machine.h
+++ b/tools/perf/util/machine.h
@@ -38,6 +38,7 @@ struct machine {
struct map_groups kmaps;
struct map *vmlinux_maps[MAP__NR_TYPES];
u64 kernel_start;
+ u32 nr_truncated_mmaps;
symbol_filter_t symbol_filter;
pid_t *current_tid;
union { /* Tool specific area */
Thanks,
Kan
>
> The callchain is:
>
> builtin-top.c
> machine__synthesize_threads()
> __machine__synthesize_threads()
> perf_event__process()
> machine__process_event()
> machine__process_mmap2_event()
>
> At some point even a event_stats may make sense to be added to struct
> machine :-)
>
> - Arnaldo