Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

tracing: Add support for multiple hist triggers per event

Allow users to define any number of hist triggers per trace event.
Any number of hist triggers may be added for a given event, which may
differ by key, value, or filter.

Reading the event's 'hist' file will display the output of all the
hist triggers defined on an event concatenated in the order they were
defined.

Link: http://lkml.kernel.org/r/48a0c8dd34c344571de880fb35e211c6d9a28961.1457029949.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
Tested-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Reviewed-by: Namhyung Kim <namhyung@kernel.org>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

authored by

Tom Zanussi and committed by
Steven Rostedt
52a7f16d 0fc3813c

+293 -41
+148 -6
Documentation/trace/events.txt
··· 550 550 551 551 'hist' triggers add a 'hist' file to each event's subdirectory. 552 552 Reading the 'hist' file for the event will dump the hash table in 553 - its entirety to stdout. Each printed hash table entry is a simple 554 - list of the keys and values comprising the entry; keys are printed 555 - first and are delineated by curly braces, and are followed by the 556 - set of value fields for the entry. By default, numeric fields are 557 - displayed as base-10 integers. This can be modified by appending 558 - any of the following modifiers to the field name: 553 + its entirety to stdout. If there are multiple hist triggers 554 + attached to an event, there will be a table for each trigger in the 555 + output. Each printed hash table entry is a simple list of the keys 556 + and values comprising the entry; keys are printed first and are 557 + delineated by curly braces, and are followed by the set of value 558 + fields for the entry. By default, numeric fields are displayed as 559 + base-10 integers. This can be modified by appending any of the 560 + following modifiers to the field name: 559 561 560 562 .hex display a number as a hex value 561 563 .sym display an address as a symbol ··· 1669 1667 . 1670 1668 . 1671 1669 . 1670 + 1671 + The following example demonstrates how multiple hist triggers can be 1672 + attached to a given event. This capability can be useful for 1673 + creating a set of different summaries derived from the same set of 1674 + events, or for comparing the effects of different filters, among 1675 + other things. 1676 + 1677 + # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \ 1678 + /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger 1679 + # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \ 1680 + /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger 1681 + # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \ 1682 + /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger 1683 + # echo 'hist:keys=skbaddr.hex:vals=len' >> \ 1684 + /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger 1685 + # echo 'hist:keys=len:vals=common_preempt_count' >> \ 1686 + /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger 1687 + 1688 + The above set of commands create four triggers differing only in 1689 + their filters, along with a completely different though fairly 1690 + nonsensical trigger. Note that in order to append multiple hist 1691 + triggers to the same file, you should use the '>>' operator to 1692 + append them ('>' will also add the new hist trigger, but will remove 1693 + any existing hist triggers beforehand). 1694 + 1695 + Displaying the contents of the 'hist' file for the event shows the 1696 + contents of all five histograms: 1697 + 1698 + # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist 1699 + 1700 + # event histogram 1701 + # 1702 + # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active] 1703 + # 1704 + 1705 + { len: 176 } hitcount: 1 common_preempt_count: 0 1706 + { len: 223 } hitcount: 1 common_preempt_count: 0 1707 + { len: 4854 } hitcount: 1 common_preempt_count: 0 1708 + { len: 395 } hitcount: 1 common_preempt_count: 0 1709 + { len: 177 } hitcount: 1 common_preempt_count: 0 1710 + { len: 446 } hitcount: 1 common_preempt_count: 0 1711 + { len: 1601 } hitcount: 1 common_preempt_count: 0 1712 + . 1713 + . 1714 + . 1715 + { len: 1280 } hitcount: 66 common_preempt_count: 0 1716 + { len: 116 } hitcount: 81 common_preempt_count: 40 1717 + { len: 708 } hitcount: 112 common_preempt_count: 0 1718 + { len: 46 } hitcount: 221 common_preempt_count: 0 1719 + { len: 1264 } hitcount: 458 common_preempt_count: 0 1720 + 1721 + Totals: 1722 + Hits: 1428 1723 + Entries: 147 1724 + Dropped: 0 1725 + 1726 + 1727 + # event histogram 1728 + # 1729 + # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active] 1730 + # 1731 + 1732 + { skbaddr: ffff8800baee5e00 } hitcount: 1 len: 130 1733 + { skbaddr: ffff88005f3d5600 } hitcount: 1 len: 1280 1734 + { skbaddr: ffff88005f3d4900 } hitcount: 1 len: 1280 1735 + { skbaddr: ffff88009fed6300 } hitcount: 1 len: 115 1736 + { skbaddr: ffff88009fe0ad00 } hitcount: 1 len: 115 1737 + { skbaddr: ffff88008cdb1900 } hitcount: 1 len: 46 1738 + { skbaddr: ffff880064b5ef00 } hitcount: 1 len: 118 1739 + { skbaddr: ffff880044e3c700 } hitcount: 1 len: 60 1740 + { skbaddr: ffff880100065900 } hitcount: 1 len: 46 1741 + { skbaddr: ffff8800d46bd500 } hitcount: 1 len: 116 1742 + { skbaddr: ffff88005f3d5f00 } hitcount: 1 len: 1280 1743 + { skbaddr: ffff880100064700 } hitcount: 1 len: 365 1744 + { skbaddr: ffff8800badb6f00 } hitcount: 1 len: 60 1745 + . 1746 + . 1747 + . 1748 + { skbaddr: ffff88009fe0be00 } hitcount: 27 len: 24677 1749 + { skbaddr: ffff88009fe0a400 } hitcount: 27 len: 23052 1750 + { skbaddr: ffff88009fe0b700 } hitcount: 31 len: 25589 1751 + { skbaddr: ffff88009fe0b600 } hitcount: 32 len: 27326 1752 + { skbaddr: ffff88006a462800 } hitcount: 68 len: 71678 1753 + { skbaddr: ffff88006a463700 } hitcount: 70 len: 72678 1754 + { skbaddr: ffff88006a462b00 } hitcount: 71 len: 77589 1755 + { skbaddr: ffff88006a463600 } hitcount: 73 len: 71307 1756 + { skbaddr: ffff88006a462200 } hitcount: 81 len: 81032 1757 + 1758 + Totals: 1759 + Hits: 1451 1760 + Entries: 318 1761 + Dropped: 0 1762 + 1763 + 1764 + # event histogram 1765 + # 1766 + # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [active] 1767 + # 1768 + 1769 + 1770 + Totals: 1771 + Hits: 0 1772 + Entries: 0 1773 + Dropped: 0 1774 + 1775 + 1776 + # event histogram 1777 + # 1778 + # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [active] 1779 + # 1780 + 1781 + { skbaddr: ffff88009fd2c300 } hitcount: 1 len: 7212 1782 + { skbaddr: ffff8800d2bcce00 } hitcount: 1 len: 7212 1783 + { skbaddr: ffff8800d2bcd700 } hitcount: 1 len: 7212 1784 + { skbaddr: ffff8800d2bcda00 } hitcount: 1 len: 21492 1785 + { skbaddr: ffff8800ae2e2d00 } hitcount: 1 len: 7212 1786 + { skbaddr: ffff8800d2bcdb00 } hitcount: 1 len: 7212 1787 + { skbaddr: ffff88006a4df500 } hitcount: 1 len: 4854 1788 + { skbaddr: ffff88008ce47b00 } hitcount: 1 len: 18636 1789 + { skbaddr: ffff8800ae2e2200 } hitcount: 1 len: 12924 1790 + { skbaddr: ffff88005f3e1000 } hitcount: 1 len: 4356 1791 + { skbaddr: ffff8800d2bcdc00 } hitcount: 2 len: 24420 1792 + { skbaddr: ffff8800d2bcc200 } hitcount: 2 len: 12996 1793 + 1794 + Totals: 1795 + Hits: 14 1796 + Entries: 12 1797 + Dropped: 0 1798 + 1799 + 1800 + # event histogram 1801 + # 1802 + # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active] 1803 + # 1804 + 1805 + 1806 + Totals: 1807 + Hits: 0 1808 + Entries: 0 1809 + Dropped: 0
+5 -3
kernel/trace/trace.c
··· 3856 3856 "\t sort field. The 'size' parameter can be used to specify more\n" 3857 3857 "\t or fewer than the default 2048 entries for the hashtable size.\n\n" 3858 3858 "\t Reading the 'hist' file for the event will dump the hash\n" 3859 - "\t table in its entirety to stdout. The default format used to\n" 3860 - "\t display a given field can be modified by appending any of the\n" 3861 - "\t following modifiers to the field name, as applicable:\n\n" 3859 + "\t table in its entirety to stdout. If there are multiple hist\n" 3860 + "\t triggers attached to an event, there will be a table for each\n" 3861 + "\t trigger in the output. The default format used to display a\n" 3862 + "\t given field can be modified by appending any of the following\n" 3863 + "\t modifiers to the field name, as applicable:\n\n" 3862 3864 "\t .hex display a number as a hex value\n" 3863 3865 "\t .sym display an address as a symbol\n" 3864 3866 "\t .sym-offset display an address as a symbol and offset\n"
+140 -32
kernel/trace/trace_events_hist.c
··· 1032 1032 return n_entries; 1033 1033 } 1034 1034 1035 - static int hist_show(struct seq_file *m, void *v) 1035 + static void hist_trigger_show(struct seq_file *m, 1036 + struct event_trigger_data *data, int n) 1036 1037 { 1037 - struct event_trigger_data *test, *data = NULL; 1038 - struct trace_event_file *event_file; 1039 1038 struct hist_trigger_data *hist_data; 1040 1039 int n_entries, ret = 0; 1041 1040 1042 - mutex_lock(&event_mutex); 1043 - 1044 - event_file = event_file_data(m->private); 1045 - if (unlikely(!event_file)) { 1046 - ret = -ENODEV; 1047 - goto out_unlock; 1048 - } 1049 - 1050 - list_for_each_entry_rcu(test, &event_file->triggers, list) { 1051 - if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) { 1052 - data = test; 1053 - break; 1054 - } 1055 - } 1056 - if (!data) 1057 - goto out_unlock; 1041 + if (n > 0) 1042 + seq_puts(m, "\n\n"); 1058 1043 1059 1044 seq_puts(m, "# event histogram\n#\n# trigger info: "); 1060 1045 data->ops->print(m, data->ops, data); 1061 - seq_puts(m, "\n"); 1046 + seq_puts(m, "#\n\n"); 1062 1047 1063 1048 hist_data = data->private_data; 1064 1049 n_entries = print_entries(m, hist_data); ··· 1055 1070 seq_printf(m, "\nTotals:\n Hits: %llu\n Entries: %u\n Dropped: %llu\n", 1056 1071 (u64)atomic64_read(&hist_data->map->hits), 1057 1072 n_entries, (u64)atomic64_read(&hist_data->map->drops)); 1073 + } 1074 + 1075 + static int hist_show(struct seq_file *m, void *v) 1076 + { 1077 + struct event_trigger_data *data; 1078 + struct trace_event_file *event_file; 1079 + int n = 0, ret = 0; 1080 + 1081 + mutex_lock(&event_mutex); 1082 + 1083 + event_file = event_file_data(m->private); 1084 + if (unlikely(!event_file)) { 1085 + ret = -ENODEV; 1086 + goto out_unlock; 1087 + } 1088 + 1089 + list_for_each_entry_rcu(data, &event_file->triggers, list) { 1090 + if (data->cmd_ops->trigger_type == ETT_EVENT_HIST) 1091 + hist_trigger_show(m, data, n++); 1092 + } 1093 + 1058 1094 out_unlock: 1059 1095 mutex_unlock(&event_mutex); 1060 1096 ··· 1239 1233 data->paused = paused; 1240 1234 } 1241 1235 1236 + static bool hist_trigger_match(struct event_trigger_data *data, 1237 + struct event_trigger_data *data_test) 1238 + { 1239 + struct tracing_map_sort_key *sort_key, *sort_key_test; 1240 + struct hist_trigger_data *hist_data, *hist_data_test; 1241 + struct hist_field *key_field, *key_field_test; 1242 + unsigned int i; 1243 + 1244 + hist_data = data->private_data; 1245 + hist_data_test = data_test->private_data; 1246 + 1247 + if (hist_data->n_vals != hist_data_test->n_vals || 1248 + hist_data->n_fields != hist_data_test->n_fields || 1249 + hist_data->n_sort_keys != hist_data_test->n_sort_keys) 1250 + return false; 1251 + 1252 + if ((data->filter_str && !data_test->filter_str) || 1253 + (!data->filter_str && data_test->filter_str)) 1254 + return false; 1255 + 1256 + for_each_hist_field(i, hist_data) { 1257 + key_field = hist_data->fields[i]; 1258 + key_field_test = hist_data_test->fields[i]; 1259 + 1260 + if (key_field->flags != key_field_test->flags) 1261 + return false; 1262 + if (key_field->field != key_field_test->field) 1263 + return false; 1264 + if (key_field->offset != key_field_test->offset) 1265 + return false; 1266 + } 1267 + 1268 + for (i = 0; i < hist_data->n_sort_keys; i++) { 1269 + sort_key = &hist_data->sort_keys[i]; 1270 + sort_key_test = &hist_data_test->sort_keys[i]; 1271 + 1272 + if (sort_key->field_idx != sort_key_test->field_idx || 1273 + sort_key->descending != sort_key_test->descending) 1274 + return false; 1275 + } 1276 + 1277 + if (data->filter_str && 1278 + (strcmp(data->filter_str, data_test->filter_str) != 0)) 1279 + return false; 1280 + 1281 + return true; 1282 + } 1283 + 1242 1284 static int hist_register_trigger(char *glob, struct event_trigger_ops *ops, 1243 1285 struct event_trigger_data *data, 1244 1286 struct trace_event_file *file) ··· 1297 1243 1298 1244 list_for_each_entry_rcu(test, &file->triggers, list) { 1299 1245 if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) { 1246 + if (!hist_trigger_match(data, test)) 1247 + continue; 1300 1248 if (hist_data->attrs->pause) 1301 1249 test->paused = true; 1302 1250 else if (hist_data->attrs->cont) ··· 1336 1280 } 1337 1281 out: 1338 1282 return ret; 1283 + } 1284 + 1285 + static void hist_unregister_trigger(char *glob, struct event_trigger_ops *ops, 1286 + struct event_trigger_data *data, 1287 + struct trace_event_file *file) 1288 + { 1289 + struct event_trigger_data *test; 1290 + bool unregistered = false; 1291 + 1292 + list_for_each_entry_rcu(test, &file->triggers, list) { 1293 + if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) { 1294 + if (!hist_trigger_match(data, test)) 1295 + continue; 1296 + unregistered = true; 1297 + list_del_rcu(&test->list); 1298 + trace_event_trigger_enable_disable(file, 0); 1299 + update_cond_flag(file); 1300 + break; 1301 + } 1302 + } 1303 + 1304 + if (unregistered && test->ops->free) 1305 + test->ops->free(test->ops, test); 1306 + } 1307 + 1308 + static void hist_unreg_all(struct trace_event_file *file) 1309 + { 1310 + struct event_trigger_data *test; 1311 + 1312 + list_for_each_entry_rcu(test, &file->triggers, list) { 1313 + if (test->cmd_ops->trigger_type == ETT_EVENT_HIST) { 1314 + list_del_rcu(&test->list); 1315 + trace_event_trigger_enable_disable(file, 0); 1316 + update_cond_flag(file); 1317 + if (test->ops->free) 1318 + test->ops->free(test->ops, test); 1319 + } 1320 + } 1339 1321 } 1340 1322 1341 1323 static int event_hist_trigger_func(struct event_command *cmd_ops, ··· 1425 1331 1426 1332 trigger_data->private_data = hist_data; 1427 1333 1334 + /* if param is non-empty, it's supposed to be a filter */ 1335 + if (param && cmd_ops->set_filter) { 1336 + ret = cmd_ops->set_filter(param, trigger_data, file); 1337 + if (ret < 0) 1338 + goto out_free; 1339 + } 1340 + 1428 1341 if (glob[0] == '!') { 1429 1342 cmd_ops->unreg(glob+1, trigger_ops, trigger_data, file); 1430 1343 ret = 0; 1431 1344 goto out_free; 1432 1345 } 1433 1346 1434 - if (!param) /* if param is non-empty, it's supposed to be a filter */ 1435 - goto out_reg; 1436 - 1437 - if (!cmd_ops->set_filter) 1438 - goto out_reg; 1439 - 1440 - ret = cmd_ops->set_filter(param, trigger_data, file); 1441 - if (ret < 0) 1442 - goto out_free; 1443 - out_reg: 1444 1347 ret = cmd_ops->reg(glob, trigger_ops, trigger_data, file); 1445 1348 /* 1446 1349 * The above returns on success the # of triggers registered, ··· 1470 1379 .flags = EVENT_CMD_FL_NEEDS_REC, 1471 1380 .func = event_hist_trigger_func, 1472 1381 .reg = hist_register_trigger, 1473 - .unreg = unregister_trigger, 1382 + .unreg = hist_unregister_trigger, 1383 + .unreg_all = hist_unreg_all, 1474 1384 .get_trigger_ops = event_hist_get_trigger_ops, 1475 1385 .set_filter = set_trigger_filter, 1476 1386 }; ··· 1498 1406 test->paused = false; 1499 1407 else 1500 1408 test->paused = true; 1501 - break; 1502 1409 } 1503 1410 } 1504 1411 } ··· 1560 1469 return ops; 1561 1470 } 1562 1471 1472 + static void hist_enable_unreg_all(struct trace_event_file *file) 1473 + { 1474 + struct event_trigger_data *test; 1475 + 1476 + list_for_each_entry_rcu(test, &file->triggers, list) { 1477 + if (test->cmd_ops->trigger_type == ETT_HIST_ENABLE) { 1478 + list_del_rcu(&test->list); 1479 + update_cond_flag(file); 1480 + trace_event_trigger_enable_disable(file, 0); 1481 + if (test->ops->free) 1482 + test->ops->free(test->ops, test); 1483 + } 1484 + } 1485 + } 1486 + 1563 1487 static struct event_command trigger_hist_enable_cmd = { 1564 1488 .name = ENABLE_HIST_STR, 1565 1489 .trigger_type = ETT_HIST_ENABLE, 1566 1490 .func = event_enable_trigger_func, 1567 1491 .reg = event_enable_register_trigger, 1568 1492 .unreg = event_enable_unregister_trigger, 1493 + .unreg_all = hist_enable_unreg_all, 1569 1494 .get_trigger_ops = hist_enable_get_trigger_ops, 1570 1495 .set_filter = set_trigger_filter, 1571 1496 }; ··· 1592 1485 .func = event_enable_trigger_func, 1593 1486 .reg = event_enable_register_trigger, 1594 1487 .unreg = event_enable_unregister_trigger, 1488 + .unreg_all = hist_enable_unreg_all, 1595 1489 .get_trigger_ops = hist_enable_get_trigger_ops, 1596 1490 .set_filter = set_trigger_filter, 1597 1491 };