Demonstrations of hardirqs, the Linux eBPF/bcc version.


This program traces hard interrupts (irqs), and stores timing statistics
in-kernel for efficiency. For example:

# ./hardirqs
Tracing hard irq event time... Hit Ctrl-C to end.
^C
HARDIRQ                    TOTAL_usecs
callfuncsingle0                      2
callfuncsingle5                      5
callfuncsingle6                      5
callfuncsingle7                     21
blkif                               66
timer7                              84
resched5                            94
resched0                            97
resched3                           102
resched7                           111
resched6                           255
timer3                             362
resched4                           367
timer5                             474
timer1                             529
timer6                             679
timer2                             746
timer4                             943
resched1                          1048
timer0                            1558
resched2                          1750
eth0                             11441

The HARDIRQ column prints the interrupt action name. While tracing, the eth0
hard irq action ran for 11441 microseconds (11 milliseconds) in total.

Many other interrupts are visible in the output: this is an 8 CPU system, and
some of these interrupts have a separate action per-CPU (eg, "timer",
"resched").


An interval can be provided, and also optionally a count. Eg, printing output
every 1 second, and including timestamps (-T):

# ./hardirqs -T 1 3
Tracing hard irq event time... Hit Ctrl-C to end.

22:16:14
HARDIRQ                    TOTAL_usecs
callfuncsingle0                      2
callfuncsingle7                      5
callfuncsingle3                      5
callfuncsingle2                      5
callfuncsingle6                      6
callfuncsingle1                     11
resched0                            32
blkif                               51
resched5                            71
resched7                            71
resched4                            72
resched6                            82
timer7                             172
resched1                           187
resched2                           236
timer3                             252
resched3                           282
timer1                             320
timer2                             374
timer6                             396
timer5                             427
timer4                             470
timer0                            1430
eth0                              7498

22:16:15
HARDIRQ                    TOTAL_usecs
callfuncsingle7                      6
callfuncsingle5                     11
callfuncsingle4                     13
timer2                              17
callfuncsingle6                     18
resched0                            21
blkif                               33
resched3                            40
resched5                            60
resched4                            69
resched6                            70
resched7                            74
timer7                              86
resched2                            91
timer3                             134
resched1                           293
timer5                             354
timer1                             433
timer6                             497
timer4                            1112
timer0                            1768
eth0                              6972

22:16:16
HARDIRQ                    TOTAL_usecs
callfuncsingle7                      5
callfuncsingle3                      5
callfuncsingle2                      6
timer3                              10
resched0                            18
callfuncsingle4                     22
resched5                            27
resched6                            44
blkif                               45
resched7                            65
resched4                            69
timer4                              77
resched2                            97
timer7                              98
resched3                           103
timer2                             169
resched1                           226
timer5                             525
timer1                             691
timer6                             697
timer0                            1415
eth0                              7152

This can be useful for quantifying where CPU cycles are spent among the hard
interrupts (summarized as the %irq column from mpstat(1)). The output above
shows that most time was spent processing for eth0 (network interface), which
was around 7 milliseconds per second (total across all CPUs).

Note that the time spent among the "timer" interrupts was low, and usually less
than one microsecond per second. Here's the hardirq per-second output when the
perf tool is performing a 999 Hertz CPU profile ("perf record -F 999 -a ..."):

22:13:59
HARDIRQ                    TOTAL_usecs
callfuncsingle7                      5
callfuncsingle5                      5
callfuncsingle3                      6
callfuncsingle4                      7
callfuncsingle6                     19
blkif                               66
resched0                            66
resched2                            82
resched7                            87
resched3                            96
resched4                           118
resched5                           120
resched6                           130
resched1                           230
timer3                             946
timer1                            1981
timer7                            2618
timer5                            3063
timer6                            3141
timer4                            3511
timer2                            3554
timer0                            5044
eth0                             16015

This sheds some light into the CPU overhead of the perf profiler, which cost
around 3 milliseconds per second. Note that I'm usually profiling at a much
lower rate, 99 Hertz, which looks like this:

22:22:12
HARDIRQ                    TOTAL_usecs
callfuncsingle3                      5
callfuncsingle6                      5
callfuncsingle5                     22
blkif                               46
resched6                            47
resched5                            57
resched4                            66
resched7                            78
resched2                            97
resched0                           214
timer2                             326
timer0                             498
timer5                             536
timer6                             576
timer1                             600
timer4                             982
resched1                          1315
timer7                            1364
timer3                            1825
resched3                          5708
eth0                              9743

Much lower (and remember to compare this to the baseline). Note that perf has
other overheads (non-irq CPU cycles, file system storage).


The distribution of interrupt run time can be printed as a histogram with the -d
option. Eg:

# ./hardirqs -d
Tracing hard irq event time... Hit Ctrl-C to end.
^C

hardirq = 'callfuncsingle1'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 0        |                                        |
      8192 -> 16383      : 1        |****************************************|

hardirq = 'callfuncsingle0'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 1        |****************************************|

hardirq = 'callfuncsingle3'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 3        |****************************************|

hardirq = 'callfuncsingle2'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 2        |****************************************|

hardirq = 'callfuncsingle5'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 5        |****************************************|

hardirq = 'callfuncsingle4'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 6        |****************************************|

hardirq = 'callfuncsingle7'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 4        |****************************************|

hardirq = 'callfuncsingle6'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 4        |****************************************|

hardirq = 'eth0'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 5102     |*********                               |
      1024 -> 2047       : 20617    |****************************************|
      2048 -> 4095       : 4832     |*********                               |
      4096 -> 8191       : 12       |                                        |

hardirq = 'timer7'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 9        |***                                     |
      2048 -> 4095       : 70       |*****************************           |
      4096 -> 8191       : 94       |****************************************|

hardirq = 'timer6'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 1        |                                        |
      2048 -> 4095       : 86       |***********                             |
      4096 -> 8191       : 295      |****************************************|
      8192 -> 16383      : 28       |***                                     |

hardirq = 'timer5'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 1        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 137      |****************************************|
      4096 -> 8191       : 123      |***********************************     |
      8192 -> 16383      : 8        |**                                      |

hardirq = 'timer4'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 46       |*********                               |
      4096 -> 8191       : 198      |****************************************|
      8192 -> 16383      : 49       |*********                               |

hardirq = 'timer3'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 4        |                                        |
      2048 -> 4095       : 210      |****************************************|
      4096 -> 8191       : 186      |***********************************     |

hardirq = 'timer2'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 245      |****************************************|
      4096 -> 8191       : 227      |*************************************   |
      8192 -> 16383      : 6        |                                        |

hardirq = 'timer1'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 6        |*                                       |
      2048 -> 4095       : 112      |************************                |
      4096 -> 8191       : 181      |****************************************|
      8192 -> 16383      : 7        |*                                       |

hardirq = 'timer0'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 887      |****************************************|
      8192 -> 16383      : 92       |****                                    |

hardirq = 'blkif'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 0        |                                        |
      2048 -> 4095       : 0        |                                        |
      4096 -> 8191       : 9        |****************************************|
      8192 -> 16383      : 7        |*******************************         |
     16384 -> 32767      : 2        |********                                |

hardirq = 'resched4'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 104      |****************************************|
      2048 -> 4095       : 80       |******************************          |

hardirq = 'resched5'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 27       |*****                                   |
      1024 -> 2047       : 216      |****************************************|
      2048 -> 4095       : 27       |*****                                   |
      4096 -> 8191       : 1        |                                        |

hardirq = 'resched6'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 480      |*******************                     |
      1024 -> 2047       : 1003     |****************************************|
      2048 -> 4095       : 64       |**                                      |

hardirq = 'resched7'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 46       |*********                               |
      1024 -> 2047       : 190      |****************************************|
      2048 -> 4095       : 42       |********                                |

hardirq = 'resched0'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 11       |****                                    |
      1024 -> 2047       : 100      |****************************************|
      2048 -> 4095       : 23       |*********                               |

hardirq = 'resched1'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 96       |********                                |
      1024 -> 2047       : 462      |****************************************|
      2048 -> 4095       : 36       |***                                     |

hardirq = 'resched2'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 120      |**************************              |
      1024 -> 2047       : 183      |****************************************|
      2048 -> 4095       : 41       |********                                |

hardirq = 'resched3'
     usecs               : count     distribution
         0 -> 1          : 0        |                                        |
         2 -> 3          : 0        |                                        |
         4 -> 7          : 0        |                                        |
         8 -> 15         : 0        |                                        |
        16 -> 31         : 0        |                                        |
        32 -> 63         : 0        |                                        |
        64 -> 127        : 0        |                                        |
       128 -> 255        : 0        |                                        |
       256 -> 511        : 0        |                                        |
       512 -> 1023       : 0        |                                        |
      1024 -> 2047       : 789      |****************************************|
      2048 -> 4095       : 39       |*                                       |


Sometimes you just want counts of events, and don't need the distribution
of times. You can use the -C or --count option:

# ./hardirqs.py -C
Tracing hard irq events... Hit Ctrl-C to end.
^C
HARDIRQ                    TOTAL_count
blkif                                2
callfuncsingle3                      8
callfuncsingle2                     10
callfuncsingle1                     18
resched7                            25
callfuncsingle6                     25
callfuncsingle5                     27
callfuncsingle0                     27
eth0                                34
resched2                            40
resched1                            66
timer7                              70
resched6                            71
resched0                            73
resched5                            79
resched4                            90
timer6                              95
timer4                             100
timer1                             109
timer2                             115
timer0                             117
timer3                             123
resched3                           140
timer5                             288


USAGE message:

# ./hardirqs -h
usage: hardirqs [-h] [-T] [-N] [-C] [-d] [interval] [outputs]

Summarize hard irq event time as histograms

positional arguments:
  interval           output interval, in seconds
  outputs            number of outputs

optional arguments:
  -h, --help         show this help message and exit
  -T, --timestamp    include timestamp on output
  -N, --nanoseconds  output in nanoseconds
  -C, --count        show event counts instead of timing
  -d, --dist         show distributions as histograms

examples:
    ./hardirqs            # sum hard irq event time
    ./hardirqs -d         # show hard irq event time as histograms
    ./hardirqs 1 10       # print 1 second summaries, 10 times
    ./hardirqs -NT 1      # 1s summaries, nanoseconds, and timestamps