perf understanding context-switches, sched:*, and cpu-clock

The name of the pictureThe name of the pictureThe name of the pictureClash Royale CLAN TAG#URR8PPP











up vote
0
down vote

favorite












I'm doing something like:



sudo perf record -a -g -e context-switches -e sched:* -e cpu-clock -F 499 -p XXXX -t YYY



This will record all scheduler tracepoints, all context-switches.



  • Does -F only affects events right?
    Like cpu-clock for 499Hz.

Also it was specified with -a, but -p -t was also specified.



  • Would that make -a useless?

Inside perf script, context switch only shows stack trace, while sched_switch shows both stack trace and switch information (next task to use the cpu).



  • How are context-switch and sched events related to?

What I have noticed is that after sched_switch, there's always a context-switch, Now I'm assuming that context-switch is the sched_switch.



In this scheduling sample:



command 7447/7447 [001] 62202.663269: 329 sched:sched_waking: comm=schedmon pid=498 prio=120 target_cpu=001
command 7447/7447 [001] 62202.663274: 335 sched:sched_wakeup: schedmon:498 [120] success=1 CPU:001
command 7447/7447 [001] 62202.702887: 43294327 sched:sched_stat_runtime: comm=command pid=7447 runtime=988313 [ns] vruntime=194195593780 [ns]
command 7447/7447 [003] 62203.127899: 1 sched:sched_migrate_task: comm=rcu_sched pid=8 prio=120 orig_cpu=1 dest_cpu=3
command 7447/7447 [001] 62203.265789: 21 sched:sched_switch: command:7447 [120] R ==> kworker/u8:2:5539 [120]


  • What is the unit of 62202.663269?

  • What is period (number after 62202.663269)?

  • In sched_waking event is comm= is the waker?

  • In sched_switch event what is [120]? what is R?

  • I noticed that there are sched:sched_stat_runtime and then sched:sched_waking for same thread. Why is this? Am I missing a sched sleep here?

  • What to look for thread sleep?

  • What to look for thread blocker? For example in condition variable wait or io, or swap, etc.

  • How is the sched:sched_stat_runtime being reported? from what it seems,it it reported when thread has consumed certain vruntime.

I'm doing this because there a significant time increase of a program running under KVM.



Thanks!









share







New contributor




Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
Check out our Code of Conduct.























    up vote
    0
    down vote

    favorite












    I'm doing something like:



    sudo perf record -a -g -e context-switches -e sched:* -e cpu-clock -F 499 -p XXXX -t YYY



    This will record all scheduler tracepoints, all context-switches.



    • Does -F only affects events right?
      Like cpu-clock for 499Hz.

    Also it was specified with -a, but -p -t was also specified.



    • Would that make -a useless?

    Inside perf script, context switch only shows stack trace, while sched_switch shows both stack trace and switch information (next task to use the cpu).



    • How are context-switch and sched events related to?

    What I have noticed is that after sched_switch, there's always a context-switch, Now I'm assuming that context-switch is the sched_switch.



    In this scheduling sample:



    command 7447/7447 [001] 62202.663269: 329 sched:sched_waking: comm=schedmon pid=498 prio=120 target_cpu=001
    command 7447/7447 [001] 62202.663274: 335 sched:sched_wakeup: schedmon:498 [120] success=1 CPU:001
    command 7447/7447 [001] 62202.702887: 43294327 sched:sched_stat_runtime: comm=command pid=7447 runtime=988313 [ns] vruntime=194195593780 [ns]
    command 7447/7447 [003] 62203.127899: 1 sched:sched_migrate_task: comm=rcu_sched pid=8 prio=120 orig_cpu=1 dest_cpu=3
    command 7447/7447 [001] 62203.265789: 21 sched:sched_switch: command:7447 [120] R ==> kworker/u8:2:5539 [120]


    • What is the unit of 62202.663269?

    • What is period (number after 62202.663269)?

    • In sched_waking event is comm= is the waker?

    • In sched_switch event what is [120]? what is R?

    • I noticed that there are sched:sched_stat_runtime and then sched:sched_waking for same thread. Why is this? Am I missing a sched sleep here?

    • What to look for thread sleep?

    • What to look for thread blocker? For example in condition variable wait or io, or swap, etc.

    • How is the sched:sched_stat_runtime being reported? from what it seems,it it reported when thread has consumed certain vruntime.

    I'm doing this because there a significant time increase of a program running under KVM.



    Thanks!









    share







    New contributor




    Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
    Check out our Code of Conduct.





















      up vote
      0
      down vote

      favorite









      up vote
      0
      down vote

      favorite











      I'm doing something like:



      sudo perf record -a -g -e context-switches -e sched:* -e cpu-clock -F 499 -p XXXX -t YYY



      This will record all scheduler tracepoints, all context-switches.



      • Does -F only affects events right?
        Like cpu-clock for 499Hz.

      Also it was specified with -a, but -p -t was also specified.



      • Would that make -a useless?

      Inside perf script, context switch only shows stack trace, while sched_switch shows both stack trace and switch information (next task to use the cpu).



      • How are context-switch and sched events related to?

      What I have noticed is that after sched_switch, there's always a context-switch, Now I'm assuming that context-switch is the sched_switch.



      In this scheduling sample:



      command 7447/7447 [001] 62202.663269: 329 sched:sched_waking: comm=schedmon pid=498 prio=120 target_cpu=001
      command 7447/7447 [001] 62202.663274: 335 sched:sched_wakeup: schedmon:498 [120] success=1 CPU:001
      command 7447/7447 [001] 62202.702887: 43294327 sched:sched_stat_runtime: comm=command pid=7447 runtime=988313 [ns] vruntime=194195593780 [ns]
      command 7447/7447 [003] 62203.127899: 1 sched:sched_migrate_task: comm=rcu_sched pid=8 prio=120 orig_cpu=1 dest_cpu=3
      command 7447/7447 [001] 62203.265789: 21 sched:sched_switch: command:7447 [120] R ==> kworker/u8:2:5539 [120]


      • What is the unit of 62202.663269?

      • What is period (number after 62202.663269)?

      • In sched_waking event is comm= is the waker?

      • In sched_switch event what is [120]? what is R?

      • I noticed that there are sched:sched_stat_runtime and then sched:sched_waking for same thread. Why is this? Am I missing a sched sleep here?

      • What to look for thread sleep?

      • What to look for thread blocker? For example in condition variable wait or io, or swap, etc.

      • How is the sched:sched_stat_runtime being reported? from what it seems,it it reported when thread has consumed certain vruntime.

      I'm doing this because there a significant time increase of a program running under KVM.



      Thanks!









      share







      New contributor




      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.











      I'm doing something like:



      sudo perf record -a -g -e context-switches -e sched:* -e cpu-clock -F 499 -p XXXX -t YYY



      This will record all scheduler tracepoints, all context-switches.



      • Does -F only affects events right?
        Like cpu-clock for 499Hz.

      Also it was specified with -a, but -p -t was also specified.



      • Would that make -a useless?

      Inside perf script, context switch only shows stack trace, while sched_switch shows both stack trace and switch information (next task to use the cpu).



      • How are context-switch and sched events related to?

      What I have noticed is that after sched_switch, there's always a context-switch, Now I'm assuming that context-switch is the sched_switch.



      In this scheduling sample:



      command 7447/7447 [001] 62202.663269: 329 sched:sched_waking: comm=schedmon pid=498 prio=120 target_cpu=001
      command 7447/7447 [001] 62202.663274: 335 sched:sched_wakeup: schedmon:498 [120] success=1 CPU:001
      command 7447/7447 [001] 62202.702887: 43294327 sched:sched_stat_runtime: comm=command pid=7447 runtime=988313 [ns] vruntime=194195593780 [ns]
      command 7447/7447 [003] 62203.127899: 1 sched:sched_migrate_task: comm=rcu_sched pid=8 prio=120 orig_cpu=1 dest_cpu=3
      command 7447/7447 [001] 62203.265789: 21 sched:sched_switch: command:7447 [120] R ==> kworker/u8:2:5539 [120]


      • What is the unit of 62202.663269?

      • What is period (number after 62202.663269)?

      • In sched_waking event is comm= is the waker?

      • In sched_switch event what is [120]? what is R?

      • I noticed that there are sched:sched_stat_runtime and then sched:sched_waking for same thread. Why is this? Am I missing a sched sleep here?

      • What to look for thread sleep?

      • What to look for thread blocker? For example in condition variable wait or io, or swap, etc.

      • How is the sched:sched_stat_runtime being reported? from what it seems,it it reported when thread has consumed certain vruntime.

      I'm doing this because there a significant time increase of a program running under KVM.



      Thanks!







      performance perf





      share







      New contributor




      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.










      share







      New contributor




      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.








      share



      share






      New contributor




      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.









      asked 5 mins ago









      Prinz Rainer Buyo

      1




      1




      New contributor




      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.





      New contributor





      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.






      Prinz Rainer Buyo is a new contributor to this site. Take care in asking for clarification, commenting, and answering.
      Check out our Code of Conduct.

























          active

          oldest

          votes











          Your Answer








          StackExchange.ready(function()
          var channelOptions =
          tags: "".split(" "),
          id: "106"
          ;
          initTagRenderer("".split(" "), "".split(" "), channelOptions);

          StackExchange.using("externalEditor", function()
          // Have to fire editor after snippets, if snippets enabled
          if (StackExchange.settings.snippets.snippetsEnabled)
          StackExchange.using("snippets", function()
          createEditor();
          );

          else
          createEditor();

          );

          function createEditor()
          StackExchange.prepareEditor(
          heartbeatType: 'answer',
          convertImagesToLinks: false,
          noModals: true,
          showLowRepImageUploadWarning: true,
          reputationToPostImages: null,
          bindNavPrevention: true,
          postfix: "",
          imageUploader:
          brandingHtml: "Powered by u003ca class="icon-imgur-white" href="https://imgur.com/"u003eu003c/au003e",
          contentPolicyHtml: "User contributions licensed under u003ca href="https://creativecommons.org/licenses/by-sa/3.0/"u003ecc by-sa 3.0 with attribution requiredu003c/au003e u003ca href="https://stackoverflow.com/legal/content-policy"u003e(content policy)u003c/au003e",
          allowUrls: true
          ,
          onDemand: true,
          discardSelector: ".discard-answer"
          ,immediatelyShowMarkdownHelp:true
          );



          );






          Prinz Rainer Buyo is a new contributor. Be nice, and check out our Code of Conduct.









           

          draft saved


          draft discarded


















          StackExchange.ready(
          function ()
          StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2funix.stackexchange.com%2fquestions%2f479049%2fperf-understanding-context-switches-sched-and-cpu-clock%23new-answer', 'question_page');

          );

          Post as a guest



































          active

          oldest

          votes













          active

          oldest

          votes









          active

          oldest

          votes






          active

          oldest

          votes








          Prinz Rainer Buyo is a new contributor. Be nice, and check out our Code of Conduct.









           

          draft saved


          draft discarded


















          Prinz Rainer Buyo is a new contributor. Be nice, and check out our Code of Conduct.












          Prinz Rainer Buyo is a new contributor. Be nice, and check out our Code of Conduct.











          Prinz Rainer Buyo is a new contributor. Be nice, and check out our Code of Conduct.













           


          draft saved


          draft discarded














          StackExchange.ready(
          function ()
          StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2funix.stackexchange.com%2fquestions%2f479049%2fperf-understanding-context-switches-sched-and-cpu-clock%23new-answer', 'question_page');

          );

          Post as a guest













































































          Popular posts from this blog

          How to check contact read email or not when send email to Individual?

          Bahrain

          Postfix configuration issue with fips on centos 7; mailgun relay