Newer
Older
1001
1002
1003
1004
1005
1006
1007
1008
1009
1010
1011
1012
1013
1014
1015
1016
1017
1018
1019
1020
1021
1022
1023
1024
1025
1026
1027
1028
1029
1030
1031
1032
1033
1034
1035
1036
1037
1038
1039
1040
1041
1042
1043
1044
1045
1046
1047
1048
1049
1050
1051
1052
1053
1054
1055
1056
1057
1058
1059
1060
1061
1062
1063
1064
1065
1066
1067
1068
1069
1070
1071
1072
1073
1074
1075
1076
1077
1078
1079
1080
1081
1082
1083
1084
1085
1086
1087
1088
1089
1090
1091
1092
1093
1094
1095
1096
1097
1098
1099
1100
1101
1102
1103
1104
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114
1115
1116
1117
1118
1119
1120
1121
1122
1123
1124
1125
1126
1127
1128
1129
1130
1131
1132
1133
1134
1135
1136
1137
1138
1139
1140
1141
1142
1143
1144
1145
1146
1147
1148
1149
1150
1151
1152
1153
1154
1155
1156
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
1167
1168
1169
1170
1171
1172
1173
1174
1175
1176
1177
1178
1179
1180
1181
1182
1183
1184
1185
1186
1187
1188
1189
1190
1191
1192
1193
1194
1195
1196
1197
1198
1199
1200
1201
1202
1203
1204
1205
1206
1207
1208
1209
1210
1211
1212
1213
1214
1215
1216
1217
1218
1219
1220
1221
1222
1223
1224
1225
1226
1227
1228
1229
1230
1231
1232
1233
1234
1235
1236
1237
1238
1239
1240
1241
1242
1243
1244
1245
1246
1247
1248
1249
1250
1251
1252
1253
1254
1255
1256
1257
1258
1259
1260
1261
1262
1263
1264
1265
1266
1267
1268
1269
1270
1271
1272
1273
1274
1275
1276
1277
1278
1279
1280
1281
1282
1283
1284
1285
1286
1287
1288
1289
1290
1291
1292
1293
1294
1295
1296
1297
1298
1299
1300
1301
1302
1303
1304
1305
1306
1307
1308
1309
1310
1311
1312
1313
1314
1315
1316
1317
1318
1319
1320
1321
1322
1323
1324
1325
1326
1327
1328
1329
1330
1331
1332
1333
1334
1335
1336
1337
1338
1339
1340
1341
1342
1343
1344
1345
1346
1347
1348
1349
1350
1351
1352
1353
1354
1355
1356
1357
1358
1359
1360
1361
1362
1363
1364
1365
1366
1367
1368
1369
1370
1371
1372
1373
1374
1375
1376
1377
1378
1379
1380
1381
1382
1383
1384
1385
1386
1387
1388
1389
1390
1391
1392
1393
1394
1395
1396
1397
1398
1399
1400
1401
1402
1403
1404
1405
1406
1407
1408
1409
1410
1411
1412
1413
1414
1415
1416
1417
1418
1419
1420
1421
1422
1423
1424
1425
1426
1427
1428
1429
1430
1431
1432
1433
1434
1435
1436
1437
1438
1439
1440
1441
1442
1443
1444
1445
1446
1447
1448
1449
1450
1451
1452
1453
1454
1455
1456
1457
1458
1459
1460
1461
1462
1463
1464
1465
1466
1467
1468
1469
1470
1471
1472
1473
1474
1475
1476
1477
1478
1479
1480
1481
1482
1483
1484
1485
1486
1487
1488
1489
1490
1491
1492
1493
1494
1495
1496
1497
1498
1499
1500
1501
1502
1503
1504
1505
1506
1507
1508
1509
1510
1511
1512
1513
1514
1515
1516
1517
1518
1519
1520
1521
1522
1523
1524
1525
1526
1527
1528
1529
1530
1531
1532
1533
1534
1535
1536
1537
1538
1539
1540
1541
1542
1543
1544
1545
1546
1547
1548
1549
1550
1551
1552
1553
1554
1555
1556
1557
1558
1559
1560
1561
1562
1563
1564
1565
1566
1567
1568
1569
1570
# echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
/sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
The aggregation continues until the netif_receive_skb is paused
again, which is what the following disable_hist event does by
creating a similar setup on the sched_process_exit event, using the
filter 'comm==wget':
# echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
/sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
Whenever a process exits and the comm field of the disable_hist
trigger filter matches 'comm==wget', the netif_receive_skb hist
trigger is disabled.
The overall effect is that netif_receive_skb events are aggregated
into the hash table for only the duration of the wget. Executing a
wget command and then listing the 'hist' file will display the
output generated by the wget command:
$ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
# cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
# trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
{ stacktrace:
__netif_receive_skb_core+0x46d/0x990
__netif_receive_skb+0x18/0x60
netif_receive_skb_internal+0x23/0x90
napi_gro_receive+0xc8/0x100
ieee80211_deliver_skb+0xd6/0x270 [mac80211]
ieee80211_rx_handlers+0xccf/0x22f0 [mac80211]
ieee80211_prepare_and_rx_handle+0x4e7/0xc40 [mac80211]
ieee80211_rx+0x31d/0x900 [mac80211]
iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
iwl_pcie_irq_handler+0xe3c/0x12f0 [iwlwifi]
irq_thread_fn+0x20/0x50
irq_thread+0x11f/0x150
kthread+0xd2/0xf0
ret_from_fork+0x42/0x70
} hitcount: 85 len: 28884
{ stacktrace:
__netif_receive_skb_core+0x46d/0x990
__netif_receive_skb+0x18/0x60
netif_receive_skb_internal+0x23/0x90
napi_gro_complete+0xa4/0xe0
dev_gro_receive+0x23a/0x360
napi_gro_receive+0x30/0x100
ieee80211_deliver_skb+0xd6/0x270 [mac80211]
ieee80211_rx_handlers+0xccf/0x22f0 [mac80211]
ieee80211_prepare_and_rx_handle+0x4e7/0xc40 [mac80211]
ieee80211_rx+0x31d/0x900 [mac80211]
iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
iwl_pcie_irq_handler+0xe3c/0x12f0 [iwlwifi]
irq_thread_fn+0x20/0x50
irq_thread+0x11f/0x150
kthread+0xd2/0xf0
} hitcount: 98 len: 664329
{ stacktrace:
__netif_receive_skb_core+0x46d/0x990
__netif_receive_skb+0x18/0x60
process_backlog+0xa8/0x150
net_rx_action+0x15d/0x340
__do_softirq+0x114/0x2c0
do_softirq_own_stack+0x1c/0x30
do_softirq+0x65/0x70
__local_bh_enable_ip+0xb5/0xc0
ip_finish_output+0x1f4/0x840
ip_output+0x6b/0xc0
ip_local_out_sk+0x31/0x40
ip_send_skb+0x1a/0x50
udp_send_skb+0x173/0x2a0
udp_sendmsg+0x2bf/0x9f0
inet_sendmsg+0x64/0xa0
sock_sendmsg+0x3d/0x50
} hitcount: 115 len: 13030
{ stacktrace:
__netif_receive_skb_core+0x46d/0x990
__netif_receive_skb+0x18/0x60
netif_receive_skb_internal+0x23/0x90
napi_gro_complete+0xa4/0xe0
napi_gro_flush+0x6d/0x90
iwl_pcie_irq_handler+0x92a/0x12f0 [iwlwifi]
irq_thread_fn+0x20/0x50
irq_thread+0x11f/0x150
kthread+0xd2/0xf0
ret_from_fork+0x42/0x70
} hitcount: 934 len: 5512212
Totals:
Hits: 1232
Entries: 4
Dropped: 0
The above shows all the netif_receive_skb callpaths and their total
lengths for the duration of the wget command.
The 'clear' hist trigger param can be used to clear the hash table.
Suppose we wanted to try another run of the previous example but
this time also wanted to see the complete list of events that went
into the histogram. In order to avoid having to set everything up
again, we can just clear the histogram first:
# echo 'hist:key=stacktrace:vals=len:clear' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
Just to verify that it is in fact cleared, here's what we now see in
the hist file:
# cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
# trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
Totals:
Hits: 0
Entries: 0
Dropped: 0
Since we want to see the detailed list of every netif_receive_skb
event occurring during the new run, which are in fact the same
events being aggregated into the hash table, we add some additional
'enable_event' events to the triggering sched_process_exec and
sched_process_exit events as such:
# echo 'enable_event:net:netif_receive_skb if filename==/usr/bin/wget' > \
/sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
# echo 'disable_event:net:netif_receive_skb if comm==wget' > \
/sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
If you read the trigger files for the sched_process_exec and
sched_process_exit triggers, you should see two triggers for each:
one enabling/disabling the hist aggregation and the other
enabling/disabling the logging of events:
# cat /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
enable_event:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
enable_hist:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
# cat /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
enable_event:net:netif_receive_skb:unlimited if comm==wget
disable_hist:net:netif_receive_skb:unlimited if comm==wget
In other words, whenever either of the sched_process_exec or
sched_process_exit events is hit and matches 'wget', it enables or
disables both the histogram and the event log, and what you end up
with is a hash table and set of events just covering the specified
duration. Run the wget command again:
$ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
Displaying the 'hist' file should show something similar to what you
saw in the last run, but this time you should also see the
individual events in the trace file:
# cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 183/1426 #P:4
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
wget-15108 [000] ..s1 31769.606929: netif_receive_skb: dev=lo skbaddr=ffff88009c353100 len=60
wget-15108 [000] ..s1 31769.606999: netif_receive_skb: dev=lo skbaddr=ffff88009c353200 len=60
dnsmasq-1382 [000] ..s1 31769.677652: netif_receive_skb: dev=lo skbaddr=ffff88009c352b00 len=130
dnsmasq-1382 [000] ..s1 31769.685917: netif_receive_skb: dev=lo skbaddr=ffff88009c352200 len=138
##### CPU 2 buffer started ####
irq/29-iwlwifi-559 [002] ..s. 31772.031529: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433d00 len=2948
irq/29-iwlwifi-559 [002] ..s. 31772.031572: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432200 len=1500
irq/29-iwlwifi-559 [002] ..s. 31772.032196: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433100 len=2948
irq/29-iwlwifi-559 [002] ..s. 31772.032761: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433000 len=2948
irq/29-iwlwifi-559 [002] ..s. 31772.033220: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432e00 len=1500
.
.
.
The following example demonstrates how multiple hist triggers can be
attached to a given event. This capability can be useful for
creating a set of different summaries derived from the same set of
events, or for comparing the effects of different filters, among
other things.
# echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=skbaddr.hex:vals=len' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:keys=len:vals=common_preempt_count' >> \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
The above set of commands create four triggers differing only in
their filters, along with a completely different though fairly
nonsensical trigger. Note that in order to append multiple hist
triggers to the same file, you should use the '>>' operator to
append them ('>' will also add the new hist trigger, but will remove
any existing hist triggers beforehand).
Displaying the contents of the 'hist' file for the event shows the
contents of all five histograms:
# cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
# event histogram
#
# trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
#
{ len: 176 } hitcount: 1 common_preempt_count: 0
{ len: 223 } hitcount: 1 common_preempt_count: 0
{ len: 4854 } hitcount: 1 common_preempt_count: 0
{ len: 395 } hitcount: 1 common_preempt_count: 0
{ len: 177 } hitcount: 1 common_preempt_count: 0
{ len: 446 } hitcount: 1 common_preempt_count: 0
{ len: 1601 } hitcount: 1 common_preempt_count: 0
.
.
.
{ len: 1280 } hitcount: 66 common_preempt_count: 0
{ len: 116 } hitcount: 81 common_preempt_count: 40
{ len: 708 } hitcount: 112 common_preempt_count: 0
{ len: 46 } hitcount: 221 common_preempt_count: 0
{ len: 1264 } hitcount: 458 common_preempt_count: 0
Totals:
Hits: 1428
Entries: 147
Dropped: 0
# event histogram
#
# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
#
{ skbaddr: ffff8800baee5e00 } hitcount: 1 len: 130
{ skbaddr: ffff88005f3d5600 } hitcount: 1 len: 1280
{ skbaddr: ffff88005f3d4900 } hitcount: 1 len: 1280
{ skbaddr: ffff88009fed6300 } hitcount: 1 len: 115
{ skbaddr: ffff88009fe0ad00 } hitcount: 1 len: 115
{ skbaddr: ffff88008cdb1900 } hitcount: 1 len: 46
{ skbaddr: ffff880064b5ef00 } hitcount: 1 len: 118
{ skbaddr: ffff880044e3c700 } hitcount: 1 len: 60
{ skbaddr: ffff880100065900 } hitcount: 1 len: 46
{ skbaddr: ffff8800d46bd500 } hitcount: 1 len: 116
{ skbaddr: ffff88005f3d5f00 } hitcount: 1 len: 1280
{ skbaddr: ffff880100064700 } hitcount: 1 len: 365
{ skbaddr: ffff8800badb6f00 } hitcount: 1 len: 60
.
.
.
{ skbaddr: ffff88009fe0be00 } hitcount: 27 len: 24677
{ skbaddr: ffff88009fe0a400 } hitcount: 27 len: 23052
{ skbaddr: ffff88009fe0b700 } hitcount: 31 len: 25589
{ skbaddr: ffff88009fe0b600 } hitcount: 32 len: 27326
{ skbaddr: ffff88006a462800 } hitcount: 68 len: 71678
{ skbaddr: ffff88006a463700 } hitcount: 70 len: 72678
{ skbaddr: ffff88006a462b00 } hitcount: 71 len: 77589
{ skbaddr: ffff88006a463600 } hitcount: 73 len: 71307
{ skbaddr: ffff88006a462200 } hitcount: 81 len: 81032
Totals:
Hits: 1451
Entries: 318
Dropped: 0
# event histogram
#
# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [active]
#
Totals:
Hits: 0
Entries: 0
Dropped: 0
# event histogram
#
# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [active]
#
{ skbaddr: ffff88009fd2c300 } hitcount: 1 len: 7212
{ skbaddr: ffff8800d2bcce00 } hitcount: 1 len: 7212
{ skbaddr: ffff8800d2bcd700 } hitcount: 1 len: 7212
{ skbaddr: ffff8800d2bcda00 } hitcount: 1 len: 21492
{ skbaddr: ffff8800ae2e2d00 } hitcount: 1 len: 7212
{ skbaddr: ffff8800d2bcdb00 } hitcount: 1 len: 7212
{ skbaddr: ffff88006a4df500 } hitcount: 1 len: 4854
{ skbaddr: ffff88008ce47b00 } hitcount: 1 len: 18636
{ skbaddr: ffff8800ae2e2200 } hitcount: 1 len: 12924
{ skbaddr: ffff88005f3e1000 } hitcount: 1 len: 4356
{ skbaddr: ffff8800d2bcdc00 } hitcount: 2 len: 24420
{ skbaddr: ffff8800d2bcc200 } hitcount: 2 len: 12996
Totals:
Hits: 14
Entries: 12
Dropped: 0
# event histogram
#
# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
#
Totals:
Hits: 0
Entries: 0
Dropped: 0
Named triggers can be used to have triggers share a common set of
histogram data. This capability is mostly useful for combining the
output of events generated by tracepoints contained inside inline
functions, but names can be used in a hist trigger on any event.
For example, these two triggers when hit will update the same 'len'
field in the shared 'foo' histogram data:
# echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
/sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
# echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
/sys/kernel/debug/tracing/events/net/netif_rx/trigger
You can see that they're updating common histogram data by reading
each event's hist files at the same time:
# cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist;
cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
# event histogram
#
# trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
#
{ skbaddr: ffff88000ad53500 } hitcount: 1 len: 46
{ skbaddr: ffff8800af5a1500 } hitcount: 1 len: 76
{ skbaddr: ffff8800d62a1900 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bccb00 } hitcount: 1 len: 468
{ skbaddr: ffff8800d3c69900 } hitcount: 1 len: 46
{ skbaddr: ffff88009ff09100 } hitcount: 1 len: 52
{ skbaddr: ffff88010f13ab00 } hitcount: 1 len: 168
{ skbaddr: ffff88006a54f400 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcc500 } hitcount: 1 len: 260
{ skbaddr: ffff880064505000 } hitcount: 1 len: 46
{ skbaddr: ffff8800baf24e00 } hitcount: 1 len: 32
{ skbaddr: ffff88009fe0ad00 } hitcount: 1 len: 46
{ skbaddr: ffff8800d3edff00 } hitcount: 1 len: 44
{ skbaddr: ffff88009fe0b400 } hitcount: 1 len: 168
{ skbaddr: ffff8800a1c55a00 } hitcount: 1 len: 40
{ skbaddr: ffff8800d2bcd100 } hitcount: 1 len: 40
{ skbaddr: ffff880064505f00 } hitcount: 1 len: 174
{ skbaddr: ffff8800a8bff200 } hitcount: 1 len: 160
{ skbaddr: ffff880044e3cc00 } hitcount: 1 len: 76
{ skbaddr: ffff8800a8bfe700 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcdc00 } hitcount: 1 len: 32
{ skbaddr: ffff8800a1f64800 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcde00 } hitcount: 1 len: 988
{ skbaddr: ffff88006a5dea00 } hitcount: 1 len: 46
{ skbaddr: ffff88002e37a200 } hitcount: 1 len: 44
{ skbaddr: ffff8800a1f32c00 } hitcount: 2 len: 676
{ skbaddr: ffff88000ad52600 } hitcount: 2 len: 107
{ skbaddr: ffff8800a1f91e00 } hitcount: 2 len: 92
{ skbaddr: ffff8800af5a0200 } hitcount: 2 len: 142
{ skbaddr: ffff8800d2bcc600 } hitcount: 2 len: 220
{ skbaddr: ffff8800ba36f500 } hitcount: 2 len: 92
{ skbaddr: ffff8800d021f800 } hitcount: 2 len: 92
{ skbaddr: ffff8800a1f33600 } hitcount: 2 len: 675
{ skbaddr: ffff8800a8bfff00 } hitcount: 3 len: 138
{ skbaddr: ffff8800d62a1300 } hitcount: 3 len: 138
{ skbaddr: ffff88002e37a100 } hitcount: 4 len: 184
{ skbaddr: ffff880064504400 } hitcount: 4 len: 184
{ skbaddr: ffff8800a8bfec00 } hitcount: 4 len: 184
{ skbaddr: ffff88000ad53700 } hitcount: 5 len: 230
{ skbaddr: ffff8800d2bcdb00 } hitcount: 5 len: 196
{ skbaddr: ffff8800a1f90000 } hitcount: 6 len: 276
{ skbaddr: ffff88006a54f900 } hitcount: 6 len: 276
Totals:
Hits: 81
Entries: 42
Dropped: 0
# event histogram
#
# trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
#
{ skbaddr: ffff88000ad53500 } hitcount: 1 len: 46
{ skbaddr: ffff8800af5a1500 } hitcount: 1 len: 76
{ skbaddr: ffff8800d62a1900 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bccb00 } hitcount: 1 len: 468
{ skbaddr: ffff8800d3c69900 } hitcount: 1 len: 46
{ skbaddr: ffff88009ff09100 } hitcount: 1 len: 52
{ skbaddr: ffff88010f13ab00 } hitcount: 1 len: 168
{ skbaddr: ffff88006a54f400 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcc500 } hitcount: 1 len: 260
{ skbaddr: ffff880064505000 } hitcount: 1 len: 46
{ skbaddr: ffff8800baf24e00 } hitcount: 1 len: 32
{ skbaddr: ffff88009fe0ad00 } hitcount: 1 len: 46
{ skbaddr: ffff8800d3edff00 } hitcount: 1 len: 44
{ skbaddr: ffff88009fe0b400 } hitcount: 1 len: 168
{ skbaddr: ffff8800a1c55a00 } hitcount: 1 len: 40
{ skbaddr: ffff8800d2bcd100 } hitcount: 1 len: 40
{ skbaddr: ffff880064505f00 } hitcount: 1 len: 174
{ skbaddr: ffff8800a8bff200 } hitcount: 1 len: 160
{ skbaddr: ffff880044e3cc00 } hitcount: 1 len: 76
{ skbaddr: ffff8800a8bfe700 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcdc00 } hitcount: 1 len: 32
{ skbaddr: ffff8800a1f64800 } hitcount: 1 len: 46
{ skbaddr: ffff8800d2bcde00 } hitcount: 1 len: 988
{ skbaddr: ffff88006a5dea00 } hitcount: 1 len: 46
{ skbaddr: ffff88002e37a200 } hitcount: 1 len: 44
{ skbaddr: ffff8800a1f32c00 } hitcount: 2 len: 676
{ skbaddr: ffff88000ad52600 } hitcount: 2 len: 107
{ skbaddr: ffff8800a1f91e00 } hitcount: 2 len: 92
{ skbaddr: ffff8800af5a0200 } hitcount: 2 len: 142
{ skbaddr: ffff8800d2bcc600 } hitcount: 2 len: 220
{ skbaddr: ffff8800ba36f500 } hitcount: 2 len: 92
{ skbaddr: ffff8800d021f800 } hitcount: 2 len: 92
{ skbaddr: ffff8800a1f33600 } hitcount: 2 len: 675
{ skbaddr: ffff8800a8bfff00 } hitcount: 3 len: 138
{ skbaddr: ffff8800d62a1300 } hitcount: 3 len: 138
{ skbaddr: ffff88002e37a100 } hitcount: 4 len: 184
{ skbaddr: ffff880064504400 } hitcount: 4 len: 184
{ skbaddr: ffff8800a8bfec00 } hitcount: 4 len: 184
{ skbaddr: ffff88000ad53700 } hitcount: 5 len: 230
{ skbaddr: ffff8800d2bcdb00 } hitcount: 5 len: 196
{ skbaddr: ffff8800a1f90000 } hitcount: 6 len: 276
{ skbaddr: ffff88006a54f900 } hitcount: 6 len: 276
Totals:
Hits: 81
Entries: 42
Dropped: 0
And here's an example that shows how to combine histogram data from
any two events even if they don't share any 'compatible' fields
other than 'hitcount' and 'stacktrace'. These commands create a
couple of triggers named 'bar' using those fields:
# echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
/sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
# echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
/sys/kernel/debug/tracing/events/net/netif_rx/trigger
And displaying the output of either shows some interesting if
somewhat confusing output:
# cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
# cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
# event histogram
#
# trigger info: hist:name=bar:keys=stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
#
{ stacktrace:
_do_fork+0x18e/0x330
kernel_thread+0x29/0x30
kthreadd+0x154/0x1b0
ret_from_fork+0x3f/0x70
} hitcount: 1
{ stacktrace:
netif_rx_internal+0xb2/0xd0
netif_rx_ni+0x20/0x70
dev_loopback_xmit+0xaa/0xd0
ip_mc_output+0x126/0x240
ip_local_out_sk+0x31/0x40
igmp_send_report+0x1e9/0x230
igmp_timer_expire+0xe9/0x120
call_timer_fn+0x39/0xf0
run_timer_softirq+0x1e1/0x290
__do_softirq+0xfd/0x290
irq_exit+0x98/0xb0
smp_apic_timer_interrupt+0x4a/0x60
apic_timer_interrupt+0x6d/0x80
cpuidle_enter+0x17/0x20
call_cpuidle+0x3b/0x60
cpu_startup_entry+0x22d/0x310
} hitcount: 1
{ stacktrace:
netif_rx_internal+0xb2/0xd0
netif_rx_ni+0x20/0x70
dev_loopback_xmit+0xaa/0xd0
ip_mc_output+0x17f/0x240
ip_local_out_sk+0x31/0x40
ip_send_skb+0x1a/0x50
udp_send_skb+0x13e/0x270
udp_sendmsg+0x2bf/0x980
inet_sendmsg+0x67/0xa0
sock_sendmsg+0x38/0x50
SYSC_sendto+0xef/0x170
SyS_sendto+0xe/0x10
entry_SYSCALL_64_fastpath+0x12/0x6a
} hitcount: 2
{ stacktrace:
netif_rx_internal+0xb2/0xd0
netif_rx+0x1c/0x60
loopback_xmit+0x6c/0xb0
dev_hard_start_xmit+0x219/0x3a0
__dev_queue_xmit+0x415/0x4f0
dev_queue_xmit_sk+0x13/0x20
ip_finish_output2+0x237/0x340
ip_finish_output+0x113/0x1d0
ip_output+0x66/0xc0
ip_local_out_sk+0x31/0x40
ip_send_skb+0x1a/0x50
udp_send_skb+0x16d/0x270
udp_sendmsg+0x2bf/0x980
inet_sendmsg+0x67/0xa0
sock_sendmsg+0x38/0x50
___sys_sendmsg+0x14e/0x270
} hitcount: 76
{ stacktrace:
netif_rx_internal+0xb2/0xd0
netif_rx+0x1c/0x60
loopback_xmit+0x6c/0xb0
dev_hard_start_xmit+0x219/0x3a0
__dev_queue_xmit+0x415/0x4f0
dev_queue_xmit_sk+0x13/0x20
ip_finish_output2+0x237/0x340
ip_finish_output+0x113/0x1d0
ip_output+0x66/0xc0
ip_local_out_sk+0x31/0x40
ip_send_skb+0x1a/0x50
udp_send_skb+0x16d/0x270
udp_sendmsg+0x2bf/0x980
inet_sendmsg+0x67/0xa0
sock_sendmsg+0x38/0x50
___sys_sendmsg+0x269/0x270
} hitcount: 77
{ stacktrace:
netif_rx_internal+0xb2/0xd0
netif_rx+0x1c/0x60
loopback_xmit+0x6c/0xb0
dev_hard_start_xmit+0x219/0x3a0
__dev_queue_xmit+0x415/0x4f0
dev_queue_xmit_sk+0x13/0x20
ip_finish_output2+0x237/0x340
ip_finish_output+0x113/0x1d0
ip_output+0x66/0xc0
ip_local_out_sk+0x31/0x40
ip_send_skb+0x1a/0x50
udp_send_skb+0x16d/0x270
udp_sendmsg+0x2bf/0x980
inet_sendmsg+0x67/0xa0
sock_sendmsg+0x38/0x50
SYSC_sendto+0xef/0x170
} hitcount: 88
{ stacktrace:
_do_fork+0x18e/0x330
SyS_clone+0x19/0x20
entry_SYSCALL_64_fastpath+0x12/0x6a
} hitcount: 244
Totals:
Hits: 489
Entries: 7
Dropped: 0