tools/hardirqs: Print results in descending order (iovisor#5148)

Users are usually interested in events that happen frequently and
consume more time. So, print the results in descending order.

Author: Bojun-Seo

tools/hardirqs.py

@@ -245,7 +245,7 @@
         dist.print_log2_hist(label, "hardirq", section_print_fn=bytes.decode)
     else:
         print("%-26s %11s" % ("HARDIRQ", "TOTAL_" + label))
-        for k, v in sorted(dist.items(), key=lambda dist: dist[1].value):
+        for k, v in sorted(dist.items(), key=lambda dist: -dist[1].value):
             print("%-26s %11d" % (k.name.decode('utf-8', 'replace'), v.value / factor))
     dist.clear()
 

tools/hardirqs_example.txt

@@ -8,28 +8,28 @@ in-kernel for efficiency. For example:
 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
+resched2                          1750
+timer0                            1558
+resched1                          1048
+timer4                             943
+timer2                             746
+timer6                             679
+timer1                             529
+timer5                             474
+resched4                           367
+timer3                             362
+resched6                           255
+resched7                           111
+resched3                           102
+resched0                            97
+resched5                            94
+timer7                              84
+blkif                               66
+callfuncsingle7                     21
+callfuncsingle6                      5
+callfuncsingle5                      5
+callfuncsingle0                      2
 
 The HARDIRQ column prints the interrupt action name. While tracing, the eth0
 hard irq action ran for 11441 microseconds (11 milliseconds) in total.
@@ -47,80 +47,80 @@ 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
+timer0                            1430
+timer4                             470
+timer5                             427
+timer6                             396
+timer2                             374
+timer1                             320
+resched3                           282
+timer3                             252
+resched2                           236
+resched1                           187
+timer7                             172
+resched6                            82
+resched4                            72
+resched7                            71
+resched5                            71
+blkif                               51
+resched0                            32
+callfuncsingle1                     11
+callfuncsingle6                      6
+callfuncsingle2                      5
+callfuncsingle3                      5
+callfuncsingle7                      5
+callfuncsingle0                      2
 
 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
+timer0                            1768
+timer4                            1112
+timer6                             497
+timer1                             433
+timer5                             354
+resched1                           293
+timer3                             134
+resched2                            91
+timer7                              86
+resched7                            74
+resched6                            70
+resched4                            69
+resched5                            60
+resched3                            40
+blkif                               33
+resched0                            21
+callfuncsingle6                     18
+timer2                              17
+callfuncsingle4                     13
+callfuncsingle5                     11
+callfuncsingle7                      6
 
 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
+timer0                            1415
+timer6                             697
+timer1                             691
+timer5                             525
+resched1                           226
+timer2                             169
+resched3                           103
+timer7                              98
+resched2                            97
+timer4                              77
+resched4                            69
+resched7                            65
+blkif                               45
+resched6                            44
+resched5                            27
+callfuncsingle4                     22
+resched0                            18
+timer3                              10
+callfuncsingle2                      6
+callfuncsingle3                      5
+callfuncsingle7                      5
 
 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
@@ -133,57 +133,57 @@ 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
+timer0                            5044
+timer2                            3554
+timer4                            3511
+timer6                            3141
+timer5                            3063
+timer7                            2618
+timer1                            1981
+timer3                             946
+resched1                           230
+resched6                           130
+resched5                           120
+resched4                           118
+resched3                            96
+resched7                            87
+resched2                            82
+resched0                            66
+blkif                               66
+callfuncsingle6                     19
+callfuncsingle4                      7
+callfuncsingle3                      6
+callfuncsingle5                      5
+callfuncsingle7                      5
 
 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
+resched3                          5708
+timer3                            1825
+timer7                            1364
+resched1                          1315
+timer4                             982
+timer1                             600
+timer6                             576
+timer5                             536
+timer0                             498
+timer2                             326
+resched0                           214
+resched2                            97
+resched7                            78
+resched4                            66
+resched5                            57
+resched6                            47
+blkif                               46
+callfuncsingle5                     22
+callfuncsingle6                      5
+callfuncsingle3                      5
 
 Much lower (and remember to compare this to the baseline). Note that perf has
 other overheads (non-irq CPU cycles, file system storage).
@@ -621,30 +621,30 @@ of times. You can use the -C or --count option:
 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
+resched3                           140
+timer3                             123
+timer0                             117
+timer2                             115
+timer1                             109
+timer4                             100
+timer6                              95
+resched4                            90
+resched5                            79
+resched0                            73
+resched6                            71
+timer7                              70
+resched1                            66
+resched2                            40
+eth0                                34
+callfuncsingle0                     27
+callfuncsingle5                     27
+callfuncsingle6                     25
+resched7                            25
+callfuncsingle1                     18
+callfuncsingle2                     10
+callfuncsingle3                      8
+blkif                                2
 
 
 USAGE message: