Search code examples
pythonperf

Redirect perf ouput


I am writing a performance monitoring script to monitor an application. Within this script, perf is called and then the application waits for a while before killing the perf process and gathering the perf information as well as other non-perf metrics. I am running the perf command by calling:

os.popen('perf stat -d -p ' + pid_executable + ' -o DATA/perf_stat.txt &')

I later kill this perf call with:

os.popen('kill -INT ' + pid_perf)

The -o option is to output the regular stdout to a file. Unfortunately, when kill is called none of the information is collected. The output is as follows:

# started on Tue Oct  5 22:28:43 2021


 Performance counter stats for process id '8056':

     <not counted>      task-clock                                                  
     <not counted>      context-switches                                            
     <not counted>      cpu-migrations                                              
     <not counted>      page-faults                                                 
     <not counted>      cycles                                                      
     <not counted>      instructions                                                
     <not counted>      branches                                                    
     <not counted>      branch-misses                                               
     <not counted>      L1-dcache-loads                                             
     <not counted>      L1-dcache-load-misses                                       
     <not counted>      LLC-loads                                                   
     <not counted>      LLC-load-misses                                             

       0.382097310 seconds time elapsed

Some events weren't counted. Try disabling the NMI watchdog:
    echo 0 > /proc/sys/kernel/nmi_watchdog
    perf stat ...
    echo 1 > /proc/sys/kernel/nmi_watchdog

My perf version is: perf version 3.10.0-957.12.1.el7.x86_64.debug

I have tried using environment variables to hold the output and redirecting using pipes, tee, and >, but this has yielded similar results. I do not have access to sudo, and the normal --timeout option is unavailable. Perf works when called normally outside of the Python script as well.

The information is written to the file, just not collected. How can I collect this information so it is properly collected?


Solution

  • Probably the process you attached to didn't generate any events during the interval perf was running for. For example if it was asleep and never woke up.

    In that case, you get <not counted> for each event where perf didn't even record a start point, e.g. no context switch to the process. (perf stat still can record and print 0 for an event, so <not counted> means something more than 0. Although for events like task-clock or cycles it's essentially synonymous because there's no way for those events not to count any counts or time while a process is running.)

    This all applies regardless of whether perf was outputting to the terminal and killed with control-C, or outputting to a file with -o. (Just tested it on my desktop with the PID of a chromium process that apparently didn't do anything in the 2 seconds I left perf running.)

    But anyway, you should treat <not collected> as 0, or a sign that you didn't sample long enough to see anything interesting.