1. 15 Dec, 2016 7 commits
    • Namhyung Kim's avatar
      perf sched timehist: Show callchains for idle stat · ba957ebb
      Namhyung Kim authored
      When --idle-hist option is used with --summary, it now shows idle stats
      with callchains like below:
      
        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
        ...
      
      Committer notes:
      
      Extra testing:
      
        # uname -a
        Linux jouet 4.8.8-300.fc25.x86_64 #1 SMP Tue Nov 15 18:10:06 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
      
      1) Run 'perf sched record -g'
      
      2) Run 'perf sched timehist --idle --summary'
      
      <SNIP>
        Idle stats by callchain:
        CPU  0: 13456.840 msec
        Idle time (msec) Count Callchains
        ---------------- ----- --------------------------------------------------
                5386.637  3283 schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_sys_poll <- sys_poll
                2750.238  2299 futex_wait_queue_me <- futex_wait <- do_futex <- sys_futex <- do_syscall_64
                1275.672  1287 schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- ep_poll <- sys_epoll_wait <- entry_SYSCALL_64_fastpath
                 936.322   452 worker_thread <- kthread <- ret_from_fork
                 741.311   385 rcu_nocb_kthread <- kthread <- ret_from_fork
                 729.385   248 schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_sys_poll <- sys_ppoll
                 365.386   229 irq_thread <- kthread <- ret_from_fork
                 338.934   265 futex_wait_queue_me <- futex_wait <- do_futex <- sys_futex <- entry_SYSCALL_64_fastpath
                 219.488   201 schedule_timeout <- rcu_gp_kthread <- kthread <- ret_from_fork
                 186.839   410 schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- ep_poll <- sys_epoll_wait <- do_syscall_64
                 142.541    59 kvm_vcpu_block <- kvm_arch_vcpu_ioctl_run <- kvm_vcpu_ioctl <- do_vfs_ioctl <- sys_ioctl
                  83.887    92 smpboot_thread_fn <- kthread <- ret_from_fork
                  62.722    96 do_exit <- do_group_exit <- 0x2a5594 <- entry_SYSCALL_64_fastpath
                  47.894    83 pipe_wait <- pipe_read <- __vfs_read <- vfs_read <- sys_read
                  46.554    61 rcu_gp_kthread <- kthread <- ret_from_fork
                  34.337    21 schedule_timeout <- intel_fbc_work_fn <- process_one_work <- worker_thread <- kthread
                  29.521    14 schedule_hrtimeout_range_clock <- schedule_hrtimeout_range <- poll_schedule_timeout <- do_select <- core_sys_select
                  20.274    10 schedule_timeout <- io_schedule_timeout <- bit_wait_io <- __wait_on_bit <- out_of_line_wait_on_bit
                  15.085    55 schedule_timeout <- unix_stream_read_generic <- unix_stream_recvmsg <- sock_recvmsg <- SYSC_recvfrom
      <SNIP>
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-7-namhyung@kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      ba957ebb
    • Namhyung Kim's avatar
      perf sched timehist: Add -I/--idle-hist option · 07235f84
      Namhyung Kim authored
      The --idle-hist option is to analyze system idle state so which process
      makes cpu to go idle.  If this option is specified, non-idle events will
      be skipped and processes switching to/from idle will be shown.
      
      This option is mostly useful when used with --summary(-only) option.  In
      the idle-time summary view, idle time is accounted to previous thread
      which is run before idle task.
      
      The example output looks like following:
      
        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
        ...
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-6-namhyung@kernel.org
      Link: http://lkml.kernel.org/r/20161213080632.19099-2-namhyung@kernel.org
      [ Merged fix sent by Namhyumg, as posted in the second Link: tag ]
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      07235f84
    • Namhyung Kim's avatar
      perf sched timehist: Skip non-idle events when necessary · a4b2b6f5
      Namhyung Kim authored
      Sometimes it only focuses on idle-related events like upcoming idle-hist
      feature.  In this case we don't want to see other event to reduce noise.
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-5-namhyung@kernel.orgSigned-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      a4b2b6f5
    • Namhyung Kim's avatar
      perf sched timehist: Save callchain when entering idle · 699b5b92
      Namhyung Kim authored
      In order to investigate the idleness reason, it is necessary to keep the
      callchains when entering idle.  This can be identified by the
      sched:sched_switch event having the next_pid field as 0.
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-4-namhyung@kernel.org
      Link: http://lkml.kernel.org/r/20161213080632.19099-1-namhyung@kernel.org
      [ Merged fix from Namhyung, see second Link: tag ]
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      699b5b92
    • Namhyung Kim's avatar
      perf sched timehist: Introduce struct idle_time_data · 3bc2fa9c
      Namhyung Kim authored
      The struct idle_time_data is to keep idle stats with callchains entering
      to the idle task.  The normal thread_runtime calculation is done
      transparently since it extends the struct thread_runtime.
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-3-namhyung@kernel.org
      [ Align struct field names ]
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      3bc2fa9c
    • Namhyung Kim's avatar
      perf sched timehist: Split is_idle_sample() · 96039c7c
      Namhyung Kim authored
      The is_idle_sample() function actually does more than determining
      whether sample come from idle task.  Split the callchain part into
      save_task_callchain() to make it clearer.
      
      Also checking prev_pid from trace data looks preferred than just
      checking sample->pid since it's possible, although rare, to have invalid
      0 pid/tid on scheduling an exiting task.
      Signed-off-by: default avatarNamhyung Kim <namhyung@kernel.org>
      Acked-by: default avatarDavid Ahern <dsahern@gmail.com>
      Cc: Andi Kleen <andi@firstfloor.org>
      Cc: Jiri Olsa <jolsa@kernel.org>
      Cc: Minchan Kim <minchan@kernel.org>
      Cc: Peter Zijlstra <peterz@infradead.org>
      Link: http://lkml.kernel.org/r/20161208144755.16673-2-namhyung@kernel.org
      [ Remove some needless () in some return statements ]
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      96039c7c
    • Jiri Olsa's avatar
      perf tools: Move headers check into bash script · aeafd623
      Jiri Olsa authored
      To make it nicer and easily maintainable.
      
      Also moving the check into fixdep sub make, so its output is not
      scattered around the build output.
      
      Removing extra $$ from mman*.h checks.
      Signed-off-by: default avatarJiri Olsa <jolsa@kernel.org>
      Tested-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      Cc: David Ahern <dsahern@gmail.com>
      Cc: Namhyung Kim <namhyung@kernel.org>
      Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
      Link: http://lkml.kernel.org/r/1481030331-31944-5-git-send-email-jolsa@kernel.org
      [ Use /bin/sh, and 'function check() {' -> 'check () {' to make it work with busybox, in Alpine Linux, for instance ]
      Signed-off-by: default avatarArnaldo Carvalho de Melo <acme@redhat.com>
      aeafd623
  2. 13 Dec, 2016 33 commits