lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Tue,  6 Dec 2016 12:40:00 +0900
From:   Namhyung Kim <namhyung@...nel.org>
To:     Arnaldo Carvalho de Melo <acme@...nel.org>
Cc:     Ingo Molnar <mingo@...nel.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Jiri Olsa <jolsa@...nel.org>,
        LKML <linux-kernel@...r.kernel.org>,
        David Ahern <dsahern@...il.com>,
        Andi Kleen <andi@...stfloor.org>,
        Minchan Kim <minchan@...nel.org>
Subject: [PATCHSET 00/10] perf sched timehist: Introduce --idle-hist option (v1)

Hi,

This patchset implements the idle hist feature which analyze reason of system
idle.  Sometimes I need to investigate what makes CPUs to go idle even though
I have jobs to do.  It may be due to I/O, waiting on lock or whatever.

To identify the reasons it only accounts events related to idle task.  Also it
shows callchains when entering to idle and time how long it's in the idle.
Although it's not perfect, it works well to help finding the reasons.

With --idle-hist option, only idle task's runtime is accounted to previous
task (which makes the cpu go to idle).  With --summary(-only) option, you can
see the total idle stat by task or callchains.

The example output looks like below:

  Idle-time summary
                            comm  parent  sched-out    idle-time   min-idle    avg-idle    max-idle  stddev  migrations
                                            (count)       (msec)     (msec)      (msec)      (msec)       %
  ---------------------------------------------------------------------------------------------------------------------
                  rcu_preempt[7]       2         95      550.872      0.011       5.798      23.146    7.63       0
                 migration/1[16]       2          1       15.558     15.558      15.558      15.558    0.00       0
                  khugepaged[39]       2          1        3.062      3.062       3.062       3.062    0.00       0
               kworker/0:1H[124]       2          2        4.728      0.611       2.364       4.116   74.12       0
            systemd-journal[167]       1          1        4.510      4.510       4.510       4.510    0.00       0
              kworker/u16:3[558]       2         13       74.737      0.080       5.749      12.960   21.96       0
             irq/34-iwlwifi[628]       2         21      118.403      0.032       5.638      23.990   24.00       0
              kworker/u17:0[673]       2          1        3.523      3.523       3.523       3.523    0.00       0
                dbus-daemon[722]       1          1        6.743      6.743       6.743       6.743    0.00       0
                    ifplugd[741]       1          1       58.826     58.826      58.826      58.826    0.00       0
            wpa_supplicant[1490]       1          1       13.302     13.302      13.302      13.302    0.00       0
               wpa_actiond[1492]       1          2        4.064      0.168       2.032       3.896   91.72       0
                   dockerd[1500]       1          1        0.055      0.055       0.055       0.055    0.00       0
              dockerd[1516/1500]    1500          1        5.732      5.732       5.732       5.732    0.00       0
              dockerd[1571/1500]    1500          1        0.020      0.020       0.020       0.020    0.00       0
  ...
  
  Idle stats:
      CPU  0 idle for    902.195  msec
      CPU  1 idle for    899.932  msec
      CPU  2 idle for    941.218  msec
      CPU  3 idle for    822.453  msec
  
  Idle stats by callchain:
    CPU  0:   902.195  msec
    Idle time (msec)     Count  Callchains
    ----------------  --------  --------------------------------------------------
             370.589        69  futex_wait_queue_me <- futex_wait <- do_futex <- sys_futex <- entry_SYSCALL_64_fastpath
             178.799        17  worker_thread <- kthread <- ret_from_fork
             128.352        17  schedule_timeout <- rcu_gp_kthread <- kthread <- ret_from_fork
             125.111        19  schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_select <- core_sys_select
              71.599        50  schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_sys_poll <- sys_poll
              23.146         1  rcu_gp_kthread <- kthread <- ret_from_fork
               4.510         1  schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- ep_poll <- sys_epoll_wait <- do_syscall_64
               0.085         1  schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_sys_poll <- do_restart_poll
  ...


The patch 1-5 are cleanup and preparations so they can be applied separately.
The patch 6-10 implements the -I/--idle-hist option.

The code is available at 'perf/timehist-idle-v1' branch in my tree:

  git://git.kernel.org/pub/scm/linux/kernel/git/namhyung/linux-perf.git 

Any comments are welcome!

Thanks,
Namhyung


Namhyung Kim (10):
  perf sched: Cleanup option processing
  perf tools: Introduce callchain_cursor__copy()
  perf sched timehist: Handle zero sample->tid properly
  perf sched timehist: Split is_idle_sample()
  perf sched timehist: Cleanup idle_max_cpu handling
  perf sched timehist: Introduce struct idle_time_data
  perf sched timehist: Save callchain when entering idle
  perf sched timehist: Skip non-idle events when necessary
  perf sched timehist: Add -I/--idle-hist option
  perf sched timehist: Show callchains for idle stat

 tools/perf/Documentation/perf-sched.txt |   4 +
 tools/perf/builtin-sched.c              | 264 +++++++++++++++++++++++++++-----
 tools/perf/util/callchain.c             |  27 ++++
 tools/perf/util/callchain.h             |   3 +
 4 files changed, 256 insertions(+), 42 deletions(-)

-- 
2.10.1

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux - Powered by OpenVZ