perf tools: Configurable per thread proc map processing time out
authorKan Liang <kan.liang@intel.com>
Wed, 17 Jun 2015 13:51:11 +0000 (09:51 -0400)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Fri, 19 Jun 2015 21:27:13 +0000 (18:27 -0300)
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 <kan.liang@intel.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Ying Huang <ying.huang@intel.com>
Link: http://lkml.kernel.org/r/1434549071-25611-2-git-send-email-kan.liang@intel.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
17 files changed:
tools/perf/Documentation/perf-kvm.txt
tools/perf/Documentation/perf-record.txt
tools/perf/Documentation/perf-top.txt
tools/perf/Documentation/perf-trace.txt
tools/perf/builtin-kvm.c
tools/perf/builtin-record.c
tools/perf/builtin-top.c
tools/perf/builtin-trace.c
tools/perf/perf.h
tools/perf/tests/code-reading.c
tools/perf/tests/dwarf-unwind.c
tools/perf/tests/mmap-thread-lookup.c
tools/perf/util/event.c
tools/perf/util/event.h
tools/perf/util/machine.c
tools/perf/util/machine.h
tools/perf/util/session.c

index 6252e776009c022dda55970dad2aa72e13610cf4..6a5bb2b170391da59b572f8c4230209fb04199e2 100644 (file)
@@ -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],
index 6fdf78625c51cdcd08048dec45adad287a3e452e..9b9d9d086680ae82885d2603d2b90435132234bc 100644 (file)
@@ -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]
index 9e5b07eb7d350938e88a770faa3296d288f6ce19..776aec4d092771ed8ea7c68c7ce205d0b7578aaa 100644 (file)
@@ -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
 --------------------------
index 1db9c8b79880e25595a45b32773c46a6b0afaf37..7ea078658a875029fb0ad03101bacdbe45e31564 100644 (file)
@@ -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
 ----------
 
index 15fecd3dc5d8c49f1fcb22e2a83649a16f808fde..74878cd75078055e437396fc9a6b201603586076 100644 (file)
@@ -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;
index 4d6cdeb94fe1e34876391098fb5302a1ae76bf33..de165a1b92402ac7a6267bd0a0c5aa30a0053c92 100644 (file)
@@ -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()
 };
 
index 70a9505aae8349db8422c10690c8ece4543acdb6..619a8696fda7c939cd0e6497abab5845813bda12 100644 (file)
@@ -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[] = {
index 4bf805b2fbf66fe77725cd4fa722a8dcb6e0699d..de5d277d1ad7cb97cac2c5da67032fc8a12ffdf6 100644 (file)
@@ -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 };
index aa79fb8a16d403ad7b0d2968fe2649c04ef44f6c..4a5827fff7993d2bbe87666af51aa939f6f9dd1d 100644 (file)
@@ -69,6 +69,7 @@ struct record_opts {
        unsigned     initial_delay;
        bool         use_clockid;
        clockid_t    clockid;
+       unsigned int proc_map_timeout;
 };
 
 struct option;
index e2a432b67d52082e96e018d563742fcefa151d50..22f8a00446e1f1b3cb6b447dbc1bc21ccfda3108 100644 (file)
@@ -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;
index 9b748e1ad46ed2848b7ed4771aca3cdf15f4e908..40b36c4624275a360d4a0f3226eaf850d6d0e825 100644 (file)
@@ -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
index 264e215c0d36a9c2e2c2e775e57d7148f1223cec..7f48efa7e295f63a72f0aa083857658ce68c45cb 100644 (file)
@@ -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;
index 416ba80c628fda9d76d1828cba63dbed8d1d45da..d7d986d8f23e5f890cc295b3b830470343f34063 100644 (file)
@@ -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;
index 39868f529cabe21db06f5398e41e6e301891affc..c53f36384b64532abec852c9e6d7a496a0d982a6 100644 (file)
@@ -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);
index 8b3b1937cb9e8774884fc39159ebc32313728866..4744673aff1b287de3a091a40edade2a709a8e52 100644 (file)
@@ -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;
 }
index cea62f6fb144d7070e520f958657b94fdc5c676c..887798e511e9f3dd382109927860269b03744246 100644 (file)
@@ -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);
index 2d882fd1f1b90b5828523cc5b419fdfbbb9b6103..aa482c10469d748fb2c6379ff854ba80f53b2b73 100644 (file)
@@ -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);
        }
 }