linux/Documentation/trace/events.txt
<<
>>
Prefs
   1                             Event Tracing
   2
   3                Documentation written by Theodore Ts'o
   4                Updated by Li Zefan and Tom Zanussi
   5
   61. Introduction
   7===============
   8
   9Tracepoints (see Documentation/trace/tracepoints.txt) can be used
  10without creating custom kernel modules to register probe functions
  11using the event tracing infrastructure.
  12
  13Not all tracepoints can be traced using the event tracing system;
  14the kernel developer must provide code snippets which define how the
  15tracing information is saved into the tracing buffer, and how the
  16tracing information should be printed.
  17
  182. Using Event Tracing
  19======================
  20
  212.1 Via the 'set_event' interface
  22---------------------------------
  23
  24The events which are available for tracing can be found in the file
  25/sys/kernel/debug/tracing/available_events.
  26
  27To enable a particular event, such as 'sched_wakeup', simply echo it
  28to /sys/kernel/debug/tracing/set_event. For example:
  29
  30        # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event
  31
  32[ Note: '>>' is necessary, otherwise it will firstly disable
  33  all the events. ]
  34
  35To disable an event, echo the event name to the set_event file prefixed
  36with an exclamation point:
  37
  38        # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event
  39
  40To disable all events, echo an empty line to the set_event file:
  41
  42        # echo > /sys/kernel/debug/tracing/set_event
  43
  44To enable all events, echo '*:*' or '*:' to the set_event file:
  45
  46        # echo *:* > /sys/kernel/debug/tracing/set_event
  47
  48The events are organized into subsystems, such as ext4, irq, sched,
  49etc., and a full event name looks like this: <subsystem>:<event>.  The
  50subsystem name is optional, but it is displayed in the available_events
  51file.  All of the events in a subsystem can be specified via the syntax
  52"<subsystem>:*"; for example, to enable all irq events, you can use the
  53command:
  54
  55        # echo 'irq:*' > /sys/kernel/debug/tracing/set_event
  56
  572.2 Via the 'enable' toggle
  58---------------------------
  59
  60The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy
  61of directories.
  62
  63To enable event 'sched_wakeup':
  64
  65        # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
  66
  67To disable it:
  68
  69        # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable
  70
  71To enable all events in sched subsystem:
  72
  73        # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
  74
  75To enable all events:
  76
  77        # echo 1 > /sys/kernel/debug/tracing/events/enable
  78
  79When reading one of these enable files, there are four results:
  80
  81 0 - all events this file affects are disabled
  82 1 - all events this file affects are enabled
  83 X - there is a mixture of events enabled and disabled
  84 ? - this file does not affect any event
  85
  862.3 Boot option
  87---------------
  88
  89In order to facilitate early boot debugging, use boot option:
  90
  91        trace_event=[event-list]
  92
  93event-list is a comma separated list of events. See section 2.1 for event
  94format.
  95
  963. Defining an event-enabled tracepoint
  97=======================================
  98
  99See The example provided in samples/trace_events
 100
 1014. Event formats
 102================
 103
 104Each trace event has a 'format' file associated with it that contains
 105a description of each field in a logged event.  This information can
 106be used to parse the binary trace stream, and is also the place to
 107find the field names that can be used in event filters (see section 5).
 108
 109It also displays the format string that will be used to print the
 110event in text mode, along with the event name and ID used for
 111profiling.
 112
 113Every event has a set of 'common' fields associated with it; these are
 114the fields prefixed with 'common_'.  The other fields vary between
 115events and correspond to the fields defined in the TRACE_EVENT
 116definition for that event.
 117
 118Each field in the format has the form:
 119
 120     field:field-type field-name; offset:N; size:N;
 121
 122where offset is the offset of the field in the trace record and size
 123is the size of the data item, in bytes.
 124
 125For example, here's the information displayed for the 'sched_wakeup'
 126event:
 127
 128# cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/format
 129
 130name: sched_wakeup
 131ID: 60
 132format:
 133        field:unsigned short common_type;       offset:0;       size:2;
 134        field:unsigned char common_flags;       offset:2;       size:1;
 135        field:unsigned char common_preempt_count;       offset:3;       size:1;
 136        field:int common_pid;   offset:4;       size:4;
 137        field:int common_tgid;  offset:8;       size:4;
 138
 139        field:char comm[TASK_COMM_LEN]; offset:12;      size:16;
 140        field:pid_t pid;        offset:28;      size:4;
 141        field:int prio; offset:32;      size:4;
 142        field:int success;      offset:36;      size:4;
 143        field:int cpu;  offset:40;      size:4;
 144
 145print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid,
 146           REC->prio, REC->success, REC->cpu
 147
 148This event contains 10 fields, the first 5 common and the remaining 5
 149event-specific.  All the fields for this event are numeric, except for
 150'comm' which is a string, a distinction important for event filtering.
 151
 1525. Event filtering
 153==================
 154
 155Trace events can be filtered in the kernel by associating boolean
 156'filter expressions' with them.  As soon as an event is logged into
 157the trace buffer, its fields are checked against the filter expression
 158associated with that event type.  An event with field values that
 159'match' the filter will appear in the trace output, and an event whose
 160values don't match will be discarded.  An event with no filter
 161associated with it matches everything, and is the default when no
 162filter has been set for an event.
 163
 1645.1 Expression syntax
 165---------------------
 166
 167A filter expression consists of one or more 'predicates' that can be
 168combined using the logical operators '&&' and '||'.  A predicate is
 169simply a clause that compares the value of a field contained within a
 170logged event with a constant value and returns either 0 or 1 depending
 171on whether the field value matched (1) or didn't match (0):
 172
 173          field-name relational-operator value
 174
 175Parentheses can be used to provide arbitrary logical groupings and
 176double-quotes can be used to prevent the shell from interpreting
 177operators as shell metacharacters.
 178
 179The field-names available for use in filters can be found in the
 180'format' files for trace events (see section 4).
 181
 182The relational-operators depend on the type of the field being tested:
 183
 184The operators available for numeric fields are:
 185
 186==, !=, <, <=, >, >=, &
 187
 188And for string fields they are:
 189
 190==, !=, ~
 191
 192The glob (~) only accepts a wild card character (*) at the start and or
 193end of the string. For example:
 194
 195  prev_comm ~ "*sh"
 196  prev_comm ~ "sh*"
 197  prev_comm ~ "*sh*"
 198
 199But does not allow for it to be within the string:
 200
 201  prev_comm ~ "ba*sh"   <-- is invalid
 202
 2035.2 Setting filters
 204-------------------
 205
 206A filter for an individual event is set by writing a filter expression
 207to the 'filter' file for the given event.
 208
 209For example:
 210
 211# cd /sys/kernel/debug/tracing/events/sched/sched_wakeup
 212# echo "common_preempt_count > 4" > filter
 213
 214A slightly more involved example:
 215
 216# cd /sys/kernel/debug/tracing/events/signal/signal_generate
 217# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter
 218
 219If there is an error in the expression, you'll get an 'Invalid
 220argument' error when setting it, and the erroneous string along with
 221an error message can be seen by looking at the filter e.g.:
 222
 223# cd /sys/kernel/debug/tracing/events/signal/signal_generate
 224# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter
 225-bash: echo: write error: Invalid argument
 226# cat filter
 227((sig >= 10 && sig < 15) || dsig == 17) && comm != bash
 228^
 229parse_error: Field not found
 230
 231Currently the caret ('^') for an error always appears at the beginning of
 232the filter string; the error message should still be useful though
 233even without more accurate position info.
 234
 2355.3 Clearing filters
 236--------------------
 237
 238To clear the filter for an event, write a '0' to the event's filter
 239file.
 240
 241To clear the filters for all events in a subsystem, write a '0' to the
 242subsystem's filter file.
 243
 2445.3 Subsystem filters
 245---------------------
 246
 247For convenience, filters for every event in a subsystem can be set or
 248cleared as a group by writing a filter expression into the filter file
 249at the root of the subsystem.  Note however, that if a filter for any
 250event within the subsystem lacks a field specified in the subsystem
 251filter, or if the filter can't be applied for any other reason, the
 252filter for that event will retain its previous setting.  This can
 253result in an unintended mixture of filters which could lead to
 254confusing (to the user who might think different filters are in
 255effect) trace output.  Only filters that reference just the common
 256fields can be guaranteed to propagate successfully to all events.
 257
 258Here are a few subsystem filter examples that also illustrate the
 259above points:
 260
 261Clear the filters on all events in the sched subsystem:
 262
 263# cd /sys/kernel/debug/tracing/events/sched
 264# echo 0 > filter
 265# cat sched_switch/filter
 266none
 267# cat sched_wakeup/filter
 268none
 269
 270Set a filter using only common fields for all events in the sched
 271subsystem (all events end up with the same filter):
 272
 273# cd /sys/kernel/debug/tracing/events/sched
 274# echo common_pid == 0 > filter
 275# cat sched_switch/filter
 276common_pid == 0
 277# cat sched_wakeup/filter
 278common_pid == 0
 279
 280Attempt to set a filter using a non-common field for all events in the
 281sched subsystem (all events but those that have a prev_pid field retain
 282their old filters):
 283
 284# cd /sys/kernel/debug/tracing/events/sched
 285# echo prev_pid == 0 > filter
 286# cat sched_switch/filter
 287prev_pid == 0
 288# cat sched_wakeup/filter
 289common_pid == 0
 290
 2915.4 PID filtering
 292-----------------
 293
 294The set_event_pid file in the same directory as the top events directory
 295exists, will filter all events from tracing any task that does not have the
 296PID listed in the set_event_pid file.
 297
 298# cd /sys/kernel/debug/tracing
 299# echo $$ > set_event_pid
 300# echo 1 > events/enabled
 301
 302Will only trace events for the current task.
 303
 304To add more PIDs without losing the PIDs already included, use '>>'.
 305
 306# echo 123 244 1 >> set_event_pid
 307
 308
 3096. Event triggers
 310=================
 311
 312Trace events can be made to conditionally invoke trigger 'commands'
 313which can take various forms and are described in detail below;
 314examples would be enabling or disabling other trace events or invoking
 315a stack trace whenever the trace event is hit.  Whenever a trace event
 316with attached triggers is invoked, the set of trigger commands
 317associated with that event is invoked.  Any given trigger can
 318additionally have an event filter of the same form as described in
 319section 5 (Event filtering) associated with it - the command will only
 320be invoked if the event being invoked passes the associated filter.
 321If no filter is associated with the trigger, it always passes.
 322
 323Triggers are added to and removed from a particular event by writing
 324trigger expressions to the 'trigger' file for the given event.
 325
 326A given event can have any number of triggers associated with it,
 327subject to any restrictions that individual commands may have in that
 328regard.
 329
 330Event triggers are implemented on top of "soft" mode, which means that
 331whenever a trace event has one or more triggers associated with it,
 332the event is activated even if it isn't actually enabled, but is
 333disabled in a "soft" mode.  That is, the tracepoint will be called,
 334but just will not be traced, unless of course it's actually enabled.
 335This scheme allows triggers to be invoked even for events that aren't
 336enabled, and also allows the current event filter implementation to be
 337used for conditionally invoking triggers.
 338
 339The syntax for event triggers is roughly based on the syntax for
 340set_ftrace_filter 'ftrace filter commands' (see the 'Filter commands'
 341section of Documentation/trace/ftrace.txt), but there are major
 342differences and the implementation isn't currently tied to it in any
 343way, so beware about making generalizations between the two.
 344
 3456.1 Expression syntax
 346---------------------
 347
 348Triggers are added by echoing the command to the 'trigger' file:
 349
 350  # echo 'command[:count] [if filter]' > trigger
 351
 352Triggers are removed by echoing the same command but starting with '!'
 353to the 'trigger' file:
 354
 355  # echo '!command[:count] [if filter]' > trigger
 356
 357The [if filter] part isn't used in matching commands when removing, so
 358leaving that off in a '!' command will accomplish the same thing as
 359having it in.
 360
 361The filter syntax is the same as that described in the 'Event
 362filtering' section above.
 363
 364For ease of use, writing to the trigger file using '>' currently just
 365adds or removes a single trigger and there's no explicit '>>' support
 366('>' actually behaves like '>>') or truncation support to remove all
 367triggers (you have to use '!' for each one added.)
 368
 3696.2 Supported trigger commands
 370------------------------------
 371
 372The following commands are supported:
 373
 374- enable_event/disable_event
 375
 376  These commands can enable or disable another trace event whenever
 377  the triggering event is hit.  When these commands are registered,
 378  the other trace event is activated, but disabled in a "soft" mode.
 379  That is, the tracepoint will be called, but just will not be traced.
 380  The event tracepoint stays in this mode as long as there's a trigger
 381  in effect that can trigger it.
 382
 383  For example, the following trigger causes kmalloc events to be
 384  traced when a read system call is entered, and the :1 at the end
 385  specifies that this enablement happens only once:
 386
 387  # echo 'enable_event:kmem:kmalloc:1' > \
 388      /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
 389
 390  The following trigger causes kmalloc events to stop being traced
 391  when a read system call exits.  This disablement happens on every
 392  read system call exit:
 393
 394  # echo 'disable_event:kmem:kmalloc' > \
 395      /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
 396
 397  The format is:
 398
 399      enable_event:<system>:<event>[:count]
 400      disable_event:<system>:<event>[:count]
 401
 402  To remove the above commands:
 403
 404  # echo '!enable_event:kmem:kmalloc:1' > \
 405      /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
 406
 407  # echo '!disable_event:kmem:kmalloc' > \
 408      /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger
 409
 410  Note that there can be any number of enable/disable_event triggers
 411  per triggering event, but there can only be one trigger per
 412  triggered event. e.g. sys_enter_read can have triggers enabling both
 413  kmem:kmalloc and sched:sched_switch, but can't have two kmem:kmalloc
 414  versions such as kmem:kmalloc and kmem:kmalloc:1 or 'kmem:kmalloc if
 415  bytes_req == 256' and 'kmem:kmalloc if bytes_alloc == 256' (they
 416  could be combined into a single filter on kmem:kmalloc though).
 417
 418- stacktrace
 419
 420  This command dumps a stacktrace in the trace buffer whenever the
 421  triggering event occurs.
 422
 423  For example, the following trigger dumps a stacktrace every time the
 424  kmalloc tracepoint is hit:
 425
 426  # echo 'stacktrace' > \
 427        /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 428
 429  The following trigger dumps a stacktrace the first 5 times a kmalloc
 430  request happens with a size >= 64K
 431
 432  # echo 'stacktrace:5 if bytes_req >= 65536' > \
 433        /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 434
 435  The format is:
 436
 437      stacktrace[:count]
 438
 439  To remove the above commands:
 440
 441  # echo '!stacktrace' > \
 442        /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 443
 444  # echo '!stacktrace:5 if bytes_req >= 65536' > \
 445        /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 446
 447  The latter can also be removed more simply by the following (without
 448  the filter):
 449
 450  # echo '!stacktrace:5' > \
 451        /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 452
 453  Note that there can be only one stacktrace trigger per triggering
 454  event.
 455
 456- snapshot
 457
 458  This command causes a snapshot to be triggered whenever the
 459  triggering event occurs.
 460
 461  The following command creates a snapshot every time a block request
 462  queue is unplugged with a depth > 1.  If you were tracing a set of
 463  events or functions at the time, the snapshot trace buffer would
 464  capture those events when the trigger event occurred:
 465
 466  # echo 'snapshot if nr_rq > 1' > \
 467        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 468
 469  To only snapshot once:
 470
 471  # echo 'snapshot:1 if nr_rq > 1' > \
 472        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 473
 474  To remove the above commands:
 475
 476  # echo '!snapshot if nr_rq > 1' > \
 477        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 478
 479  # echo '!snapshot:1 if nr_rq > 1' > \
 480        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 481
 482  Note that there can be only one snapshot trigger per triggering
 483  event.
 484
 485- traceon/traceoff
 486
 487  These commands turn tracing on and off when the specified events are
 488  hit. The parameter determines how many times the tracing system is
 489  turned on and off. If unspecified, there is no limit.
 490
 491  The following command turns tracing off the first time a block
 492  request queue is unplugged with a depth > 1.  If you were tracing a
 493  set of events or functions at the time, you could then examine the
 494  trace buffer to see the sequence of events that led up to the
 495  trigger event:
 496
 497  # echo 'traceoff:1 if nr_rq > 1' > \
 498        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 499
 500  To always disable tracing when nr_rq  > 1 :
 501
 502  # echo 'traceoff if nr_rq > 1' > \
 503        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 504
 505  To remove the above commands:
 506
 507  # echo '!traceoff:1 if nr_rq > 1' > \
 508        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 509
 510  # echo '!traceoff if nr_rq > 1' > \
 511        /sys/kernel/debug/tracing/events/block/block_unplug/trigger
 512
 513  Note that there can be only one traceon or traceoff trigger per
 514  triggering event.
 515
 516- hist
 517
 518  This command aggregates event hits into a hash table keyed on one or
 519  more trace event format fields (or stacktrace) and a set of running
 520  totals derived from one or more trace event format fields and/or
 521  event counts (hitcount).
 522
 523  The format of a hist trigger is as follows:
 524
 525        hist:keys=<field1[,field2,...]>[:values=<field1[,field2,...]>]
 526          [:sort=<field1[,field2,...]>][:size=#entries][:pause][:continue]
 527          [:clear][:name=histname1] [if <filter>]
 528
 529  When a matching event is hit, an entry is added to a hash table
 530  using the key(s) and value(s) named.  Keys and values correspond to
 531  fields in the event's format description.  Values must correspond to
 532  numeric fields - on an event hit, the value(s) will be added to a
 533  sum kept for that field.  The special string 'hitcount' can be used
 534  in place of an explicit value field - this is simply a count of
 535  event hits.  If 'values' isn't specified, an implicit 'hitcount'
 536  value will be automatically created and used as the only value.
 537  Keys can be any field, or the special string 'stacktrace', which
 538  will use the event's kernel stacktrace as the key.  The keywords
 539  'keys' or 'key' can be used to specify keys, and the keywords
 540  'values', 'vals', or 'val' can be used to specify values.  Compound
 541  keys consisting of up to two fields can be specified by the 'keys'
 542  keyword.  Hashing a compound key produces a unique entry in the
 543  table for each unique combination of component keys, and can be
 544  useful for providing more fine-grained summaries of event data.
 545  Additionally, sort keys consisting of up to two fields can be
 546  specified by the 'sort' keyword.  If more than one field is
 547  specified, the result will be a 'sort within a sort': the first key
 548  is taken to be the primary sort key and the second the secondary
 549  key.  If a hist trigger is given a name using the 'name' parameter,
 550  its histogram data will be shared with other triggers of the same
 551  name, and trigger hits will update this common data.  Only triggers
 552  with 'compatible' fields can be combined in this way; triggers are
 553  'compatible' if the fields named in the trigger share the same
 554  number and type of fields and those fields also have the same names.
 555  Note that any two events always share the compatible 'hitcount' and
 556  'stacktrace' fields and can therefore be combined using those
 557  fields, however pointless that may be.
 558
 559  'hist' triggers add a 'hist' file to each event's subdirectory.
 560  Reading the 'hist' file for the event will dump the hash table in
 561  its entirety to stdout.  If there are multiple hist triggers
 562  attached to an event, there will be a table for each trigger in the
 563  output.  The table displayed for a named trigger will be the same as
 564  any other instance having the same name. Each printed hash table
 565  entry is a simple list of the keys and values comprising the entry;
 566  keys are printed first and are delineated by curly braces, and are
 567  followed by the set of value fields for the entry.  By default,
 568  numeric fields are displayed as base-10 integers.  This can be
 569  modified by appending any of the following modifiers to the field
 570  name:
 571
 572        .hex        display a number as a hex value
 573        .sym        display an address as a symbol
 574        .sym-offset display an address as a symbol and offset
 575        .syscall    display a syscall id as a system call name
 576        .execname   display a common_pid as a program name
 577
 578  Note that in general the semantics of a given field aren't
 579  interpreted when applying a modifier to it, but there are some
 580  restrictions to be aware of in this regard:
 581
 582    - only the 'hex' modifier can be used for values (because values
 583      are essentially sums, and the other modifiers don't make sense
 584      in that context).
 585    - the 'execname' modifier can only be used on a 'common_pid'.  The
 586      reason for this is that the execname is simply the 'comm' value
 587      saved for the 'current' process when an event was triggered,
 588      which is the same as the common_pid value saved by the event
 589      tracing code.  Trying to apply that comm value to other pid
 590      values wouldn't be correct, and typically events that care save
 591      pid-specific comm fields in the event itself.
 592
 593  A typical usage scenario would be the following to enable a hist
 594  trigger, read its current contents, and then turn it off:
 595
 596  # echo 'hist:keys=skbaddr.hex:vals=len' > \
 597    /sys/kernel/debug/tracing/events/net/netif_rx/trigger
 598
 599  # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
 600
 601  # echo '!hist:keys=skbaddr.hex:vals=len' > \
 602    /sys/kernel/debug/tracing/events/net/netif_rx/trigger
 603
 604  The trigger file itself can be read to show the details of the
 605  currently attached hist trigger.  This information is also displayed
 606  at the top of the 'hist' file when read.
 607
 608  By default, the size of the hash table is 2048 entries.  The 'size'
 609  parameter can be used to specify more or fewer than that.  The units
 610  are in terms of hashtable entries - if a run uses more entries than
 611  specified, the results will show the number of 'drops', the number
 612  of hits that were ignored.  The size should be a power of 2 between
 613  128 and 131072 (any non- power-of-2 number specified will be rounded
 614  up).
 615
 616  The 'sort' parameter can be used to specify a value field to sort
 617  on.  The default if unspecified is 'hitcount' and the default sort
 618  order is 'ascending'.  To sort in the opposite direction, append
 619  .descending' to the sort key.
 620
 621  The 'pause' parameter can be used to pause an existing hist trigger
 622  or to start a hist trigger but not log any events until told to do
 623  so.  'continue' or 'cont' can be used to start or restart a paused
 624  hist trigger.
 625
 626  The 'clear' parameter will clear the contents of a running hist
 627  trigger and leave its current paused/active state.
 628
 629  Note that the 'pause', 'cont', and 'clear' parameters should be
 630  applied using 'append' shell operator ('>>') if applied to an
 631  existing trigger, rather than via the '>' operator, which will cause
 632  the trigger to be removed through truncation.
 633
 634- enable_hist/disable_hist
 635
 636  The enable_hist and disable_hist triggers can be used to have one
 637  event conditionally start and stop another event's already-attached
 638  hist trigger.  Any number of enable_hist and disable_hist triggers
 639  can be attached to a given event, allowing that event to kick off
 640  and stop aggregations on a host of other events.
 641
 642  The format is very similar to the enable/disable_event triggers:
 643
 644      enable_hist:<system>:<event>[:count]
 645      disable_hist:<system>:<event>[:count]
 646
 647  Instead of enabling or disabling the tracing of the target event
 648  into the trace buffer as the enable/disable_event triggers do, the
 649  enable/disable_hist triggers enable or disable the aggregation of
 650  the target event into a hash table.
 651
 652  A typical usage scenario for the enable_hist/disable_hist triggers
 653  would be to first set up a paused hist trigger on some event,
 654  followed by an enable_hist/disable_hist pair that turns the hist
 655  aggregation on and off when conditions of interest are hit:
 656
 657  # echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
 658    /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
 659
 660  # echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
 661    /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
 662
 663  # echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
 664    /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
 665
 666  The above sets up an initially paused hist trigger which is unpaused
 667  and starts aggregating events when a given program is executed, and
 668  which stops aggregating when the process exits and the hist trigger
 669  is paused again.
 670
 671  The examples below provide a more concrete illustration of the
 672  concepts and typical usage patterns discussed above.
 673
 674
 6756.2 'hist' trigger examples
 676---------------------------
 677
 678  The first set of examples creates aggregations using the kmalloc
 679  event.  The fields that can be used for the hist trigger are listed
 680  in the kmalloc event's format file:
 681
 682    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/format
 683    name: kmalloc
 684    ID: 374
 685    format:
 686        field:unsigned short common_type;       offset:0;       size:2; signed:0;
 687        field:unsigned char common_flags;       offset:2;       size:1; signed:0;
 688        field:unsigned char common_preempt_count;               offset:3;       size:1; signed:0;
 689        field:int common_pid;                                   offset:4;       size:4; signed:1;
 690
 691        field:unsigned long call_site;                          offset:8;       size:8; signed:0;
 692        field:const void * ptr;                                 offset:16;      size:8; signed:0;
 693        field:size_t bytes_req;                                 offset:24;      size:8; signed:0;
 694        field:size_t bytes_alloc;                               offset:32;      size:8; signed:0;
 695        field:gfp_t gfp_flags;                                  offset:40;      size:4; signed:0;
 696
 697  We'll start by creating a hist trigger that generates a simple table
 698  that lists the total number of bytes requested for each function in
 699  the kernel that made one or more calls to kmalloc:
 700
 701    # echo 'hist:key=call_site:val=bytes_req' > \
 702            /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 703
 704  This tells the tracing system to create a 'hist' trigger using the
 705  call_site field of the kmalloc event as the key for the table, which
 706  just means that each unique call_site address will have an entry
 707  created for it in the table.  The 'val=bytes_req' parameter tells
 708  the hist trigger that for each unique entry (call_site) in the
 709  table, it should keep a running total of the number of bytes
 710  requested by that call_site.
 711
 712  We'll let it run for awhile and then dump the contents of the 'hist'
 713  file in the kmalloc event's subdirectory (for readability, a number
 714  of entries have been omitted):
 715
 716    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 717    # trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
 718
 719    { call_site: 18446744072106379007 } hitcount:          1  bytes_req:        176
 720    { call_site: 18446744071579557049 } hitcount:          1  bytes_req:       1024
 721    { call_site: 18446744071580608289 } hitcount:          1  bytes_req:      16384
 722    { call_site: 18446744071581827654 } hitcount:          1  bytes_req:         24
 723    { call_site: 18446744071580700980 } hitcount:          1  bytes_req:          8
 724    { call_site: 18446744071579359876 } hitcount:          1  bytes_req:        152
 725    { call_site: 18446744071580795365 } hitcount:          3  bytes_req:        144
 726    { call_site: 18446744071581303129 } hitcount:          3  bytes_req:        144
 727    { call_site: 18446744071580713234 } hitcount:          4  bytes_req:       2560
 728    { call_site: 18446744071580933750 } hitcount:          4  bytes_req:        736
 729    .
 730    .
 731    .
 732    { call_site: 18446744072106047046 } hitcount:         69  bytes_req:       5576
 733    { call_site: 18446744071582116407 } hitcount:         73  bytes_req:       2336
 734    { call_site: 18446744072106054684 } hitcount:        136  bytes_req:     140504
 735    { call_site: 18446744072106224230 } hitcount:        136  bytes_req:      19584
 736    { call_site: 18446744072106078074 } hitcount:        153  bytes_req:       2448
 737    { call_site: 18446744072106062406 } hitcount:        153  bytes_req:      36720
 738    { call_site: 18446744071582507929 } hitcount:        153  bytes_req:      37088
 739    { call_site: 18446744072102520590 } hitcount:        273  bytes_req:      10920
 740    { call_site: 18446744071582143559 } hitcount:        358  bytes_req:        716
 741    { call_site: 18446744072106465852 } hitcount:        417  bytes_req:      56712
 742    { call_site: 18446744072102523378 } hitcount:        485  bytes_req:      27160
 743    { call_site: 18446744072099568646 } hitcount:       1676  bytes_req:      33520
 744
 745    Totals:
 746        Hits: 4610
 747        Entries: 45
 748        Dropped: 0
 749
 750  The output displays a line for each entry, beginning with the key
 751  specified in the trigger, followed by the value(s) also specified in
 752  the trigger.  At the beginning of the output is a line that displays
 753  the trigger info, which can also be displayed by reading the
 754  'trigger' file:
 755
 756    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 757    hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
 758
 759  At the end of the output are a few lines that display the overall
 760  totals for the run.  The 'Hits' field shows the total number of
 761  times the event trigger was hit, the 'Entries' field shows the total
 762  number of used entries in the hash table, and the 'Dropped' field
 763  shows the number of hits that were dropped because the number of
 764  used entries for the run exceeded the maximum number of entries
 765  allowed for the table (normally 0, but if not a hint that you may
 766  want to increase the size of the table using the 'size' parameter).
 767
 768  Notice in the above output that there's an extra field, 'hitcount',
 769  which wasn't specified in the trigger.  Also notice that in the
 770  trigger info output, there's a parameter, 'sort=hitcount', which
 771  wasn't specified in the trigger either.  The reason for that is that
 772  every trigger implicitly keeps a count of the total number of hits
 773  attributed to a given entry, called the 'hitcount'.  That hitcount
 774  information is explicitly displayed in the output, and in the
 775  absence of a user-specified sort parameter, is used as the default
 776  sort field.
 777
 778  The value 'hitcount' can be used in place of an explicit value in
 779  the 'values' parameter if you don't really need to have any
 780  particular field summed and are mainly interested in hit
 781  frequencies.
 782
 783  To turn the hist trigger off, simply call up the trigger in the
 784  command history and re-execute it with a '!' prepended:
 785
 786    # echo '!hist:key=call_site:val=bytes_req' > \
 787           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 788
 789  Finally, notice that the call_site as displayed in the output above
 790  isn't really very useful.  It's an address, but normally addresses
 791  are displayed in hex.  To have a numeric field displayed as a hex
 792  value, simply append '.hex' to the field name in the trigger:
 793
 794    # echo 'hist:key=call_site.hex:val=bytes_req' > \
 795           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 796
 797    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 798    # trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
 799
 800    { call_site: ffffffffa026b291 } hitcount:          1  bytes_req:        433
 801    { call_site: ffffffffa07186ff } hitcount:          1  bytes_req:        176
 802    { call_site: ffffffff811ae721 } hitcount:          1  bytes_req:      16384
 803    { call_site: ffffffff811c5134 } hitcount:          1  bytes_req:          8
 804    { call_site: ffffffffa04a9ebb } hitcount:          1  bytes_req:        511
 805    { call_site: ffffffff8122e0a6 } hitcount:          1  bytes_req:         12
 806    { call_site: ffffffff8107da84 } hitcount:          1  bytes_req:        152
 807    { call_site: ffffffff812d8246 } hitcount:          1  bytes_req:         24
 808    { call_site: ffffffff811dc1e5 } hitcount:          3  bytes_req:        144
 809    { call_site: ffffffffa02515e8 } hitcount:          3  bytes_req:        648
 810    { call_site: ffffffff81258159 } hitcount:          3  bytes_req:        144
 811    { call_site: ffffffff811c80f4 } hitcount:          4  bytes_req:        544
 812    .
 813    .
 814    .
 815    { call_site: ffffffffa06c7646 } hitcount:        106  bytes_req:       8024
 816    { call_site: ffffffffa06cb246 } hitcount:        132  bytes_req:      31680
 817    { call_site: ffffffffa06cef7a } hitcount:        132  bytes_req:       2112
 818    { call_site: ffffffff8137e399 } hitcount:        132  bytes_req:      23232
 819    { call_site: ffffffffa06c941c } hitcount:        185  bytes_req:     171360
 820    { call_site: ffffffffa06f2a66 } hitcount:        185  bytes_req:      26640
 821    { call_site: ffffffffa036a70e } hitcount:        265  bytes_req:      10600
 822    { call_site: ffffffff81325447 } hitcount:        292  bytes_req:        584
 823    { call_site: ffffffffa072da3c } hitcount:        446  bytes_req:      60656
 824    { call_site: ffffffffa036b1f2 } hitcount:        526  bytes_req:      29456
 825    { call_site: ffffffffa0099c06 } hitcount:       1780  bytes_req:      35600
 826
 827    Totals:
 828        Hits: 4775
 829        Entries: 46
 830        Dropped: 0
 831
 832  Even that's only marginally more useful - while hex values do look
 833  more like addresses, what users are typically more interested in
 834  when looking at text addresses are the corresponding symbols
 835  instead.  To have an address displayed as symbolic value instead,
 836  simply append '.sym' or '.sym-offset' to the field name in the
 837  trigger:
 838
 839    # echo 'hist:key=call_site.sym:val=bytes_req' > \
 840           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 841
 842    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 843    # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
 844
 845    { call_site: [ffffffff810adcb9] syslog_print_all                              } hitcount:          1  bytes_req:       1024
 846    { call_site: [ffffffff8154bc62] usb_control_msg                               } hitcount:          1  bytes_req:          8
 847    { call_site: [ffffffffa00bf6fe] hidraw_send_report [hid]                      } hitcount:          1  bytes_req:          7
 848    { call_site: [ffffffff8154acbe] usb_alloc_urb                                 } hitcount:          1  bytes_req:        192
 849    { call_site: [ffffffffa00bf1ca] hidraw_report_event [hid]                     } hitcount:          1  bytes_req:          7
 850    { call_site: [ffffffff811e3a25] __seq_open_private                            } hitcount:          1  bytes_req:         40
 851    { call_site: [ffffffff8109524a] alloc_fair_sched_group                        } hitcount:          2  bytes_req:        128
 852    { call_site: [ffffffff811febd5] fsnotify_alloc_group                          } hitcount:          2  bytes_req:        528
 853    { call_site: [ffffffff81440f58] __tty_buffer_request_room                     } hitcount:          2  bytes_req:       2624
 854    { call_site: [ffffffff81200ba6] inotify_new_group                             } hitcount:          2  bytes_req:         96
 855    { call_site: [ffffffffa05e19af] ieee80211_start_tx_ba_session [mac80211]      } hitcount:          2  bytes_req:        464
 856    { call_site: [ffffffff81672406] tcp_get_metrics                               } hitcount:          2  bytes_req:        304
 857    { call_site: [ffffffff81097ec2] alloc_rt_sched_group                          } hitcount:          2  bytes_req:        128
 858    { call_site: [ffffffff81089b05] sched_create_group                            } hitcount:          2  bytes_req:       1424
 859    .
 860    .
 861    .
 862    { call_site: [ffffffffa04a580c] intel_crtc_page_flip [i915]                   } hitcount:       1185  bytes_req:     123240
 863    { call_site: [ffffffffa0287592] drm_mode_page_flip_ioctl [drm]                } hitcount:       1185  bytes_req:     104280
 864    { call_site: [ffffffffa04c4a3c] intel_plane_duplicate_state [i915]            } hitcount:       1402  bytes_req:     190672
 865    { call_site: [ffffffff812891ca] ext4_find_extent                              } hitcount:       1518  bytes_req:     146208
 866    { call_site: [ffffffffa029070e] drm_vma_node_allow [drm]                      } hitcount:       1746  bytes_req:      69840
 867    { call_site: [ffffffffa045e7c4] i915_gem_do_execbuffer.isra.23 [i915]         } hitcount:       2021  bytes_req:     792312
 868    { call_site: [ffffffffa02911f2] drm_modeset_lock_crtc [drm]                   } hitcount:       2592  bytes_req:     145152
 869    { call_site: [ffffffffa0489a66] intel_ring_begin [i915]                       } hitcount:       2629  bytes_req:     378576
 870    { call_site: [ffffffffa046041c] i915_gem_execbuffer2 [i915]                   } hitcount:       2629  bytes_req:    3783248
 871    { call_site: [ffffffff81325607] apparmor_file_alloc_security                  } hitcount:       5192  bytes_req:      10384
 872    { call_site: [ffffffffa00b7c06] hid_report_raw_event [hid]                    } hitcount:       5529  bytes_req:     110584
 873    { call_site: [ffffffff8131ebf7] aa_alloc_task_context                         } hitcount:      21943  bytes_req:     702176
 874    { call_site: [ffffffff8125847d] ext4_htree_store_dirent                       } hitcount:      55759  bytes_req:    5074265
 875
 876    Totals:
 877        Hits: 109928
 878        Entries: 71
 879        Dropped: 0
 880
 881  Because the default sort key above is 'hitcount', the above shows a
 882  the list of call_sites by increasing hitcount, so that at the bottom
 883  we see the functions that made the most kmalloc calls during the
 884  run.  If instead we we wanted to see the top kmalloc callers in
 885  terms of the number of bytes requested rather than the number of
 886  calls, and we wanted the top caller to appear at the top, we can use
 887  the 'sort' parameter, along with the 'descending' modifier:
 888
 889    # echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
 890           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 891
 892    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 893    # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
 894
 895    { call_site: [ffffffffa046041c] i915_gem_execbuffer2 [i915]                   } hitcount:       2186  bytes_req:    3397464
 896    { call_site: [ffffffffa045e7c4] i915_gem_do_execbuffer.isra.23 [i915]         } hitcount:       1790  bytes_req:     712176
 897    { call_site: [ffffffff8125847d] ext4_htree_store_dirent                       } hitcount:       8132  bytes_req:     513135
 898    { call_site: [ffffffff811e2a1b] seq_buf_alloc                                 } hitcount:        106  bytes_req:     440128
 899    { call_site: [ffffffffa0489a66] intel_ring_begin [i915]                       } hitcount:       2186  bytes_req:     314784
 900    { call_site: [ffffffff812891ca] ext4_find_extent                              } hitcount:       2174  bytes_req:     208992
 901    { call_site: [ffffffff811ae8e1] __kmalloc                                     } hitcount:          8  bytes_req:     131072
 902    { call_site: [ffffffffa04c4a3c] intel_plane_duplicate_state [i915]            } hitcount:        859  bytes_req:     116824
 903    { call_site: [ffffffffa02911f2] drm_modeset_lock_crtc [drm]                   } hitcount:       1834  bytes_req:     102704
 904    { call_site: [ffffffffa04a580c] intel_crtc_page_flip [i915]                   } hitcount:        972  bytes_req:     101088
 905    { call_site: [ffffffffa0287592] drm_mode_page_flip_ioctl [drm]                } hitcount:        972  bytes_req:      85536
 906    { call_site: [ffffffffa00b7c06] hid_report_raw_event [hid]                    } hitcount:       3333  bytes_req:      66664
 907    { call_site: [ffffffff8137e559] sg_kmalloc                                    } hitcount:        209  bytes_req:      61632
 908    .
 909    .
 910    .
 911    { call_site: [ffffffff81095225] alloc_fair_sched_group                        } hitcount:          2  bytes_req:        128
 912    { call_site: [ffffffff81097ec2] alloc_rt_sched_group                          } hitcount:          2  bytes_req:        128
 913    { call_site: [ffffffff812d8406] copy_semundo                                  } hitcount:          2  bytes_req:         48
 914    { call_site: [ffffffff81200ba6] inotify_new_group                             } hitcount:          1  bytes_req:         48
 915    { call_site: [ffffffffa027121a] drm_getmagic [drm]                            } hitcount:          1  bytes_req:         48
 916    { call_site: [ffffffff811e3a25] __seq_open_private                            } hitcount:          1  bytes_req:         40
 917    { call_site: [ffffffff811c52f4] bprm_change_interp                            } hitcount:          2  bytes_req:         16
 918    { call_site: [ffffffff8154bc62] usb_control_msg                               } hitcount:          1  bytes_req:          8
 919    { call_site: [ffffffffa00bf1ca] hidraw_report_event [hid]                     } hitcount:          1  bytes_req:          7
 920    { call_site: [ffffffffa00bf6fe] hidraw_send_report [hid]                      } hitcount:          1  bytes_req:          7
 921
 922    Totals:
 923        Hits: 32133
 924        Entries: 81
 925        Dropped: 0
 926
 927  To display the offset and size information in addition to the symbol
 928  name, just use 'sym-offset' instead:
 929
 930    # echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
 931           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 932
 933    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 934    # trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
 935
 936    { call_site: [ffffffffa046041c] i915_gem_execbuffer2+0x6c/0x2c0 [i915]                  } hitcount:       4569  bytes_req:    3163720
 937    { call_site: [ffffffffa0489a66] intel_ring_begin+0xc6/0x1f0 [i915]                      } hitcount:       4569  bytes_req:     657936
 938    { call_site: [ffffffffa045e7c4] i915_gem_do_execbuffer.isra.23+0x694/0x1020 [i915]      } hitcount:       1519  bytes_req:     472936
 939    { call_site: [ffffffffa045e646] i915_gem_do_execbuffer.isra.23+0x516/0x1020 [i915]      } hitcount:       3050  bytes_req:     211832
 940    { call_site: [ffffffff811e2a1b] seq_buf_alloc+0x1b/0x50                                 } hitcount:         34  bytes_req:     148384
 941    { call_site: [ffffffffa04a580c] intel_crtc_page_flip+0xbc/0x870 [i915]                  } hitcount:       1385  bytes_req:     144040
 942    { call_site: [ffffffff811ae8e1] __kmalloc+0x191/0x1b0                                   } hitcount:          8  bytes_req:     131072
 943    { call_site: [ffffffffa0287592] drm_mode_page_flip_ioctl+0x282/0x360 [drm]              } hitcount:       1385  bytes_req:     121880
 944    { call_site: [ffffffffa02911f2] drm_modeset_lock_crtc+0x32/0x100 [drm]                  } hitcount:       1848  bytes_req:     103488
 945    { call_site: [ffffffffa04c4a3c] intel_plane_duplicate_state+0x2c/0xa0 [i915]            } hitcount:        461  bytes_req:      62696
 946    { call_site: [ffffffffa029070e] drm_vma_node_allow+0x2e/0xd0 [drm]                      } hitcount:       1541  bytes_req:      61640
 947    { call_site: [ffffffff815f8d7b] sk_prot_alloc+0xcb/0x1b0                                } hitcount:         57  bytes_req:      57456
 948    .
 949    .
 950    .
 951    { call_site: [ffffffff8109524a] alloc_fair_sched_group+0x5a/0x1a0                       } hitcount:          2  bytes_req:        128
 952    { call_site: [ffffffffa027b921] drm_vm_open_locked+0x31/0xa0 [drm]                      } hitcount:          3  bytes_req:         96
 953    { call_site: [ffffffff8122e266] proc_self_follow_link+0x76/0xb0                         } hitcount:          8  bytes_req:         96
 954    { call_site: [ffffffff81213e80] load_elf_binary+0x240/0x1650                            } hitcount:          3  bytes_req:         84
 955    { call_site: [ffffffff8154bc62] usb_control_msg+0x42/0x110                              } hitcount:          1  bytes_req:          8
 956    { call_site: [ffffffffa00bf6fe] hidraw_send_report+0x7e/0x1a0 [hid]                     } hitcount:          1  bytes_req:          7
 957    { call_site: [ffffffffa00bf1ca] hidraw_report_event+0x8a/0x120 [hid]                    } hitcount:          1  bytes_req:          7
 958
 959    Totals:
 960        Hits: 26098
 961        Entries: 64
 962        Dropped: 0
 963
 964  We can also add multiple fields to the 'values' parameter.  For
 965  example, we might want to see the total number of bytes allocated
 966  alongside bytes requested, and display the result sorted by bytes
 967  allocated in a descending order:
 968
 969    # echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
 970           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
 971
 972    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
 973    # trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc.descending:size=2048 [active]
 974
 975    { call_site: [ffffffffa046041c] i915_gem_execbuffer2 [i915]                   } hitcount:       7403  bytes_req:    4084360  bytes_alloc:    5958016
 976    { call_site: [ffffffff811e2a1b] seq_buf_alloc                                 } hitcount:        541  bytes_req:    2213968  bytes_alloc:    2228224
 977    { call_site: [ffffffffa0489a66] intel_ring_begin [i915]                       } hitcount:       7404  bytes_req:    1066176  bytes_alloc:    1421568
 978    { call_site: [ffffffffa045e7c4] i915_gem_do_execbuffer.isra.23 [i915]         } hitcount:       1565  bytes_req:     557368  bytes_alloc:    1037760
 979    { call_site: [ffffffff8125847d] ext4_htree_store_dirent                       } hitcount:       9557  bytes_req:     595778  bytes_alloc:     695744
 980    { call_site: [ffffffffa045e646] i915_gem_do_execbuffer.isra.23 [i915]         } hitcount:       5839  bytes_req:     430680  bytes_alloc:     470400
 981    { call_site: [ffffffffa04c4a3c] intel_plane_duplicate_state [i915]            } hitcount:       2388  bytes_req:     324768  bytes_alloc:     458496
 982    { call_site: [ffffffffa02911f2] drm_modeset_lock_crtc [drm]                   } hitcount:       3911  bytes_req:     219016  bytes_alloc:     250304
 983    { call_site: [ffffffff815f8d7b] sk_prot_alloc                                 } hitcount:        235  bytes_req:     236880  bytes_alloc:     240640
 984    { call_site: [ffffffff8137e559] sg_kmalloc                                    } hitcount:        557  bytes_req:     169024  bytes_alloc:     221760
 985    { call_site: [ffffffffa00b7c06] hid_report_raw_event [hid]                    } hitcount:       9378  bytes_req:     187548  bytes_alloc:     206312
 986    { call_site: [ffffffffa04a580c] intel_crtc_page_flip [i915]                   } hitcount:       1519  bytes_req:     157976  bytes_alloc:     194432
 987    .
 988    .
 989    .
 990    { call_site: [ffffffff8109bd3b] sched_autogroup_create_attach                 } hitcount:          2  bytes_req:        144  bytes_alloc:        192
 991    { call_site: [ffffffff81097ee8] alloc_rt_sched_group                          } hitcount:          2  bytes_req:        128  bytes_alloc:        128
 992    { call_site: [ffffffff8109524a] alloc_fair_sched_group                        } hitcount:          2  bytes_req:        128  bytes_alloc:        128
 993    { call_site: [ffffffff81095225] alloc_fair_sched_group                        } hitcount:          2  bytes_req:        128  bytes_alloc:        128
 994    { call_site: [ffffffff81097ec2] alloc_rt_sched_group                          } hitcount:          2  bytes_req:        128  bytes_alloc:        128
 995    { call_site: [ffffffff81213e80] load_elf_binary                               } hitcount:          3  bytes_req:         84  bytes_alloc:         96
 996    { call_site: [ffffffff81079a2e] kthread_create_on_node                        } hitcount:          1  bytes_req:         56  bytes_alloc:         64
 997    { call_site: [ffffffffa00bf6fe] hidraw_send_report [hid]                      } hitcount:          1  bytes_req:          7  bytes_alloc:          8
 998    { call_site: [ffffffff8154bc62] usb_control_msg                               } hitcount:          1  bytes_req:          8  bytes_alloc:          8
 999    { call_site: [ffffffffa00bf1ca] hidraw_report_event [hid]                     } hitcount:          1  bytes_req:          7  bytes_alloc:          8
1000
1001    Totals:
1002        Hits: 66598
1003        Entries: 65
1004        Dropped: 0
1005
1006  Finally, to finish off our kmalloc example, instead of simply having
1007  the hist trigger display symbolic call_sites, we can have the hist
1008  trigger additionally display the complete set of kernel stack traces
1009  that led to each call_site.  To do that, we simply use the special
1010  value 'stacktrace' for the key parameter:
1011
1012    # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
1013           /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger
1014
1015  The above trigger will use the kernel stack trace in effect when an
1016  event is triggered as the key for the hash table.  This allows the
1017  enumeration of every kernel callpath that led up to a particular
1018  event, along with a running total of any of the event fields for
1019  that event.  Here we tally bytes requested and bytes allocated for
1020  every callpath in the system that led up to a kmalloc (in this case
1021  every callpath to a kmalloc for a kernel compile):
1022
1023    # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
1024    # trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
1025
1026    { stacktrace:
1027         __kmalloc_track_caller+0x10b/0x1a0
1028         kmemdup+0x20/0x50
1029         hidraw_report_event+0x8a/0x120 [hid]
1030         hid_report_raw_event+0x3ea/0x440 [hid]
1031         hid_input_report+0x112/0x190 [hid]
1032         hid_irq_in+0xc2/0x260 [usbhid]
1033         __usb_hcd_giveback_urb+0x72/0x120
1034         usb_giveback_urb_bh+0x9e/0xe0
1035         tasklet_hi_action+0xf8/0x100
1036         __do_softirq+0x114/0x2c0
1037         irq_exit+0xa5/0xb0
1038         do_IRQ+0x5a/0xf0
1039         ret_from_intr+0x0/0x30
1040         cpuidle_enter+0x17/0x20
1041         cpu_startup_entry+0x315/0x3e0
1042         rest_init+0x7c/0x80
1043    } hitcount:          3  bytes_req:         21  bytes_alloc:         24
1044    { stacktrace:
1045         __kmalloc_track_caller+0x10b/0x1a0
1046         kmemdup+0x20/0x50
1047         hidraw_report_event+0x8a/0x120 [hid]
1048         hid_report_raw_event+0x3ea/0x440 [hid]
1049         hid_input_report+0x112/0x190 [hid]
1050         hid_irq_in+0xc2/0x260 [usbhid]
1051         __usb_hcd_giveback_urb+0x72/0x120
1052         usb_giveback_urb_bh+0x9e/0xe0
1053         tasklet_hi_action+0xf8/0x100
1054         __do_softirq+0x114/0x2c0
1055         irq_exit+0xa5/0xb0
1056         do_IRQ+0x5a/0xf0
1057         ret_from_intr+0x0/0x30
1058    } hitcount:          3  bytes_req:         21  bytes_alloc:         24
1059    { stacktrace:
1060         kmem_cache_alloc_trace+0xeb/0x150
1061         aa_alloc_task_context+0x27/0x40
1062         apparmor_cred_prepare+0x1f/0x50
1063         security_prepare_creds+0x16/0x20
1064         prepare_creds+0xdf/0x1a0
1065         SyS_capset+0xb5/0x200
1066         system_call_fastpath+0x12/0x6a
1067    } hitcount:          1  bytes_req:         32  bytes_alloc:         32
1068    .
1069    .
1070    .
1071    { stacktrace:
1072         __kmalloc+0x11b/0x1b0
1073         i915_gem_execbuffer2+0x6c/0x2c0 [i915]
1074         drm_ioctl+0x349/0x670 [drm]
1075         do_vfs_ioctl+0x2f0/0x4f0
1076         SyS_ioctl+0x81/0xa0
1077         system_call_fastpath+0x12/0x6a
1078    } hitcount:      17726  bytes_req:   13944120  bytes_alloc:   19593808
1079    { stacktrace:
1080         __kmalloc+0x11b/0x1b0
1081         load_elf_phdrs+0x76/0xa0
1082         load_elf_binary+0x102/0x1650
1083         search_binary_handler+0x97/0x1d0
1084         do_execveat_common.isra.34+0x551/0x6e0
1085         SyS_execve+0x3a/0x50
1086         return_from_execve+0x0/0x23
1087    } hitcount:      33348  bytes_req:   17152128  bytes_alloc:   20226048
1088    { stacktrace:
1089         kmem_cache_alloc_trace+0xeb/0x150
1090         apparmor_file_alloc_security+0x27/0x40
1091         security_file_alloc+0x16/0x20
1092         get_empty_filp+0x93/0x1c0
1093         path_openat+0x31/0x5f0
1094         do_filp_open+0x3a/0x90
1095         do_sys_open+0x128/0x220
1096         SyS_open+0x1e/0x20
1097         system_call_fastpath+0x12/0x6a
1098    } hitcount:    4766422  bytes_req:    9532844  bytes_alloc:   38131376
1099    { stacktrace:
1100         __kmalloc+0x11b/0x1b0
1101         seq_buf_alloc+0x1b/0x50
1102         seq_read+0x2cc/0x370
1103         proc_reg_read+0x3d/0x80
1104         __vfs_read+0x28/0xe0
1105         vfs_read+0x86/0x140
1106         SyS_read+0x46/0xb0
1107         system_call_fastpath+0x12/0x6a
1108    } hitcount:      19133  bytes_req:   78368768  bytes_alloc:   78368768
1109
1110    Totals:
1111        Hits: 6085872
1112        Entries: 253
1113        Dropped: 0
1114
1115  If you key a hist trigger on common_pid, in order for example to
1116  gather and display sorted totals for each process, you can use the
1117  special .execname modifier to display the executable names for the
1118  processes in the table rather than raw pids.  The example below
1119  keeps a per-process sum of total bytes read:
1120
1121    # echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
1122           /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger
1123
1124    # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/hist
1125    # trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
1126
1127    { common_pid: gnome-terminal  [      3196] } hitcount:        280  count:    1093512
1128    { common_pid: Xorg            [      1309] } hitcount:        525  count:     256640
1129    { common_pid: compiz          [      2889] } hitcount:         59  count:     254400
1130    { common_pid: bash            [      8710] } hitcount:          3  count:      66369
1131    { common_pid: dbus-daemon-lau [      8703] } hitcount:         49  count:      47739
1132    { common_pid: irqbalance      [      1252] } hitcount:         27  count:      27648
1133    { common_pid: 01ifupdown      [      8705] } hitcount:          3  count:      17216
1134    { common_pid: dbus-daemon     [       772] } hitcount:         10  count:      12396
1135    { common_pid: Socket Thread   [      8342] } hitcount:         11  count:      11264
1136    { common_pid: nm-dhcp-client. [      8701] } hitcount:          6  count:       7424
1137    { common_pid: gmain           [      1315] } hitcount:         18  count:       6336
1138    .
1139    .
1140    .
1141    { common_pid: postgres        [      1892] } hitcount:          2  count:         32
1142    { common_pid: postgres        [      1891] } hitcount:          2  count:         32
1143    { common_pid: gmain           [      8704] } hitcount:          2  count:         32
1144    { common_pid: upstart-dbus-br [      2740] } hitcount:         21  count:         21
1145    { common_pid: nm-dispatcher.a [      8696] } hitcount:          1  count:         16
1146    { common_pid: indicator-datet [      2904] } hitcount:          1  count:         16
1147    { common_pid: gdbus           [      2998] } hitcount:          1  count:         16
1148    { common_pid: rtkit-daemon    [      2052] } hitcount:          1  count:          8
1149    { common_pid: init            [         1] } hitcount:          2  count:          2
1150
1151    Totals:
1152        Hits: 2116
1153        Entries: 51
1154        Dropped: 0
1155
1156  Similarly, if you key a hist trigger on syscall id, for example to
1157  gather and display a list of systemwide syscall hits, you can use
1158  the special .syscall modifier to display the syscall names rather
1159  than raw ids.  The example below keeps a running total of syscall
1160  counts for the system during the run:
1161
1162    # echo 'hist:key=id.syscall:val=hitcount' > \
1163           /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
1164
1165    # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
1166    # trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
1167
1168    { id: sys_fsync                     [ 74] } hitcount:          1
1169    { id: sys_newuname                  [ 63] } hitcount:          1
1170    { id: sys_prctl                     [157] } hitcount:          1
1171    { id: sys_statfs                    [137] } hitcount:          1
1172    { id: sys_symlink                   [ 88] } hitcount:          1
1173    { id: sys_sendmmsg                  [307] } hitcount:          1
1174    { id: sys_semctl                    [ 66] } hitcount:          1
1175    { id: sys_readlink                  [ 89] } hitcount:          3
1176    { id: sys_bind                      [ 49] } hitcount:          3
1177    { id: sys_getsockname               [ 51] } hitcount:          3
1178    { id: sys_unlink                    [ 87] } hitcount:          3
1179    { id: sys_rename                    [ 82] } hitcount:          4
1180    { id: unknown_syscall               [ 58] } hitcount:          4
1181    { id: sys_connect                   [ 42] } hitcount:          4
1182    { id: sys_getpid                    [ 39] } hitcount:          4
1183    .
1184    .
1185    .
1186    { id: sys_rt_sigprocmask            [ 14] } hitcount:        952
1187    { id: sys_futex                     [202] } hitcount:       1534
1188    { id: sys_write                     [  1] } hitcount:       2689
1189    { id: sys_setitimer                 [ 38] } hitcount:       2797
1190    { id: sys_read                      [  0] } hitcount:       3202
1191    { id: sys_select                    [ 23] } hitcount:       3773
1192    { id: sys_writev                    [ 20] } hitcount:       4531
1193    { id: sys_poll                      [  7] } hitcount:       8314
1194    { id: sys_recvmsg                   [ 47] } hitcount:      13738
1195    { id: sys_ioctl                     [ 16] } hitcount:      21843
1196
1197    Totals:
1198        Hits: 67612
1199        Entries: 72
1200        Dropped: 0
1201
1202    The syscall counts above provide a rough overall picture of system
1203    call activity on the system; we can see for example that the most
1204    popular system call on this system was the 'sys_ioctl' system call.
1205
1206    We can use 'compound' keys to refine that number and provide some
1207    further insight as to which processes exactly contribute to the
1208    overall ioctl count.
1209
1210    The command below keeps a hitcount for every unique combination of
1211    system call id and pid - the end result is essentially a table
1212    that keeps a per-pid sum of system call hits.  The results are
1213    sorted using the system call id as the primary key, and the
1214    hitcount sum as the secondary key:
1215
1216    # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' > \
1217           /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
1218
1219    # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
1220    # trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:size=2048 [active]
1221
1222    { id: sys_read                      [  0], common_pid: rtkit-daemon    [      1877] } hitcount:          1
1223    { id: sys_read                      [  0], common_pid: gdbus           [      2976] } hitcount:          1
1224    { id: sys_read                      [  0], common_pid: console-kit-dae [      3400] } hitcount:          1
1225    { id: sys_read                      [  0], common_pid: postgres        [      1865] } hitcount:          1
1226    { id: sys_read                      [  0], common_pid: deja-dup-monito [      3543] } hitcount:          2
1227    { id: sys_read                      [  0], common_pid: NetworkManager  [       890] } hitcount:          2
1228    { id: sys_read                      [  0], common_pid: evolution-calen [      3048] } hitcount:          2
1229    { id: sys_read                      [  0], common_pid: postgres        [      1864] } hitcount:          2
1230    { id: sys_read                      [  0], common_pid: nm-applet       [      3022] } hitcount:          2
1231    { id: sys_read                      [  0], common_pid: whoopsie        [      1212] } hitcount:          2
1232    .
1233    .
1234    .
1235    { id: sys_ioctl                     [ 16], common_pid: bash            [      8479] } hitcount:          1
1236    { id: sys_ioctl                     [ 16], common_pid: bash            [      3472] } hitcount:         12
1237    { id: sys_ioctl                     [ 16], common_pid: gnome-terminal  [      3199] } hitcount:         16
1238    { id: sys_ioctl                     [ 16], common_pid: Xorg            [      1267] } hitcount:       1808
1239    { id: sys_ioctl                     [ 16], common_pid: compiz          [      2994] } hitcount:       5580
1240    .
1241    .
1242    .
1243    { id: sys_waitid                    [247], common_pid: upstart-dbus-br [      2690] } hitcount:          3
1244    { id: sys_waitid                    [247], common_pid: upstart-dbus-br [      2688] } hitcount:         16
1245    { id: sys_inotify_add_watch         [254], common_pid: gmain           [       975] } hitcount:          2
1246    { id: sys_inotify_add_watch         [254], common_pid: gmain           [      3204] } hitcount:          4
1247    { id: sys_inotify_add_watch         [254], common_pid: gmain           [      2888] } hitcount:          4
1248    { id: sys_inotify_add_watch         [254], common_pid: gmain           [      3003] } hitcount:          4
1249    { id: sys_inotify_add_watch         [254], common_pid: gmain           [      2873] } hitcount:          4
1250    { id: sys_inotify_add_watch         [254], common_pid: gmain           [      3196] } hitcount:          6
1251    { id: sys_openat                    [257], common_pid: java            [      2623] } hitcount:          2
1252    { id: sys_eventfd2                  [290], common_pid: ibus-ui-gtk3    [      2760] } hitcount:          4
1253    { id: sys_eventfd2                  [290], common_pid: compiz          [      2994] } hitcount:          6
1254
1255    Totals:
1256        Hits: 31536
1257        Entries: 323
1258        Dropped: 0
1259
1260    The above list does give us a breakdown of the ioctl syscall by
1261    pid, but it also gives us quite a bit more than that, which we
1262    don't really care about at the moment.  Since we know the syscall
1263    id for sys_ioctl (16, displayed next to the sys_ioctl name), we
1264    can use that to filter out all the other syscalls:
1265
1266    # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount if id == 16' > \
1267           /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
1268
1269    # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
1270    # trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:size=2048 if id == 16 [active]
1271
1272    { id: sys_ioctl                     [ 16], common_pid: gmain           [      2769] } hitcount:          1
1273    { id: sys_ioctl                     [ 16], common_pid: evolution-addre [      8571] } hitcount:          1
1274    { id: sys_ioctl                     [ 16], common_pid: gmain           [      3003] } hitcount:          1
1275    { id: sys_ioctl                     [ 16], common_pid: gmain           [      2781] } hitcount:          1
1276    { id: sys_ioctl                     [ 16], common_pid: gmain           [      2829] } hitcount:          1
1277    { id: sys_ioctl                     [ 16], common_pid: bash            [      8726] } hitcount:          1
1278    { id: sys_ioctl                     [ 16], common_pid: bash            [      8508] } hitcount:          1
1279    { id: sys_ioctl                     [ 16], common_pid: gmain           [      2970] } hitcount:          1
1280    { id: sys_ioctl                     [ 16], common_pid: gmain           [      2768] } hitcount:          1
1281    .
1282    .
1283    .
1284    { id: sys_ioctl                     [ 16], common_pid: pool            [      8559] } hitcount:         45
1285    { id: sys_ioctl                     [ 16], common_pid: pool            [      8555] } hitcount:         48
1286    { id: sys_ioctl                     [ 16], common_pid: pool            [      8551] } hitcount:         48
1287    { id: sys_ioctl                     [ 16], common_pid: avahi-daemon    [       896] } hitcount:         66
1288    { id: sys_ioctl                     [ 16], common_pid: Xorg            [      1267] } hitcount:      26674
1289    { id: sys_ioctl                     [ 16], common_pid: compiz          [      2994] } hitcount:      73443
1290
1291    Totals:
1292        Hits: 101162
1293        Entries: 103
1294        Dropped: 0
1295
1296    The above output shows that 'compiz' and 'Xorg' are far and away
1297    the heaviest ioctl callers (which might lead to questions about
1298    whether they really need to be making all those calls and to
1299    possible avenues for further investigation.)
1300
1301    The compound key examples used a key and a sum value (hitcount) to
1302    sort the output, but we can just as easily use two keys instead.
1303    Here's an example where we use a compound key composed of the the
1304    common_pid and size event fields.  Sorting with pid as the primary
1305    key and 'size' as the secondary key allows us to display an
1306    ordered summary of the recvfrom sizes, with counts, received by
1307    each process:
1308
1309    # echo 'hist:key=common_pid.execname,size:val=hitcount:sort=common_pid,size' > \
1310           /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/trigger
1311
1312    # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/hist
1313    # trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:size=2048 [active]
1314
1315    { common_pid: smbd            [       784], size:          4 } hitcount:          1
1316    { common_pid: dnsmasq         [      1412], size:       4096 } hitcount:        672
1317    { common_pid: postgres        [      1796], size:       1000 } hitcount:          6
1318    { common_pid: postgres        [      1867], size:       1000 } hitcount:         10
1319    { common_pid: bamfdaemon      [      2787], size:         28 } hitcount:          2
1320    { common_pid: bamfdaemon      [      2787], size:      14360 } hitcount:          1
1321    { common_pid: compiz          [      2994], size:          8 } hitcount:          1
1322    { common_pid: compiz          [      2994], size:         20 } hitcount:         11
1323    { common_pid: gnome-terminal  [      3199], size:          4 } hitcount:          2
1324    { common_pid: firefox         [      8817], size:          4 } hitcount:          1
1325    { common_pid: firefox         [      8817], size:          8 } hitcount:          5
1326    { common_pid: firefox         [      8817], size:        588 } hitcount:          2
1327    { common_pid: firefox         [      8817], size:        628 } hitcount:          1
1328    { common_pid: firefox         [      8817], size:       6944 } hitcount:          1
1329    { common_pid: firefox         [      8817], size:     408880 } hitcount:          2
1330    { common_pid: firefox         [      8822], size:          8 } hitcount:          2
1331    { common_pid: firefox         [      8822], size:        160 } hitcount:          2
1332    { common_pid: firefox         [      8822], size:        320 } hitcount:          2
1333    { common_pid: firefox         [      8822], size:        352 } hitcount:          1
1334    .
1335    .
1336    .
1337    { common_pid: pool            [      8923], size:       1960 } hitcount:         10
1338    { common_pid: pool            [      8923], size:       2048 } hitcount:         10
1339    { common_pid: pool            [      8924], size:       1960 } hitcount:         10
1340    { common_pid: pool            [      8924], size:       2048 } hitcount:         10
1341    { common_pid: pool            [      8928], size:       1964 } hitcount:          4
1342    { common_pid: pool            [      8928], size:       1965 } hitcount:          2
1343    { common_pid: pool            [      8928], size:       2048 } hitcount:          6
1344    { common_pid: pool            [      8929], size:       1982 } hitcount:          1
1345    { common_pid: pool            [      8929], size:       2048 } hitcount:          1
1346
1347    Totals:
1348        Hits: 2016
1349        Entries: 224
1350        Dropped: 0
1351
1352  The above example also illustrates the fact that although a compound
1353  key is treated as a single entity for hashing purposes, the sub-keys
1354  it's composed of can be accessed independently.
1355
1356  The next example uses a string field as the hash key and
1357  demonstrates how you can manually pause and continue a hist trigger.
1358  In this example, we'll aggregate fork counts and don't expect a
1359  large number of entries in the hash table, so we'll drop it to a
1360  much smaller number, say 256:
1361
1362    # echo 'hist:key=child_comm:val=hitcount:size=256' > \
1363           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
1364
1365    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1366    # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
1367
1368    { child_comm: dconf worker                        } hitcount:          1
1369    { child_comm: ibus-daemon                         } hitcount:          1
1370    { child_comm: whoopsie                            } hitcount:          1
1371    { child_comm: smbd                                } hitcount:          1
1372    { child_comm: gdbus                               } hitcount:          1
1373    { child_comm: kthreadd                            } hitcount:          1
1374    { child_comm: dconf worker                        } hitcount:          1
1375    { child_comm: evolution-alarm                     } hitcount:          2
1376    { child_comm: Socket Thread                       } hitcount:          2
1377    { child_comm: postgres                            } hitcount:          2
1378    { child_comm: bash                                } hitcount:          3
1379    { child_comm: compiz                              } hitcount:          3
1380    { child_comm: evolution-sourc                     } hitcount:          4
1381    { child_comm: dhclient                            } hitcount:          4
1382    { child_comm: pool                                } hitcount:          5
1383    { child_comm: nm-dispatcher.a                     } hitcount:          8
1384    { child_comm: firefox                             } hitcount:          8
1385    { child_comm: dbus-daemon                         } hitcount:          8
1386    { child_comm: glib-pacrunner                      } hitcount:         10
1387    { child_comm: evolution                           } hitcount:         23
1388
1389    Totals:
1390        Hits: 89
1391        Entries: 20
1392        Dropped: 0
1393
1394  If we want to pause the hist trigger, we can simply append :pause to
1395  the command that started the trigger.  Notice that the trigger info
1396  displays as [paused]:
1397
1398    # echo 'hist:key=child_comm:val=hitcount:size=256:pause' >> \
1399           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
1400
1401    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1402    # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
1403
1404    { child_comm: dconf worker                        } hitcount:          1
1405    { child_comm: kthreadd                            } hitcount:          1
1406    { child_comm: dconf worker                        } hitcount:          1
1407    { child_comm: gdbus                               } hitcount:          1
1408    { child_comm: ibus-daemon                         } hitcount:          1
1409    { child_comm: Socket Thread                       } hitcount:          2
1410    { child_comm: evolution-alarm                     } hitcount:          2
1411    { child_comm: smbd                                } hitcount:          2
1412    { child_comm: bash                                } hitcount:          3
1413    { child_comm: whoopsie                            } hitcount:          3
1414    { child_comm: compiz                              } hitcount:          3
1415    { child_comm: evolution-sourc                     } hitcount:          4
1416    { child_comm: pool                                } hitcount:          5
1417    { child_comm: postgres                            } hitcount:          6
1418    { child_comm: firefox                             } hitcount:          8
1419    { child_comm: dhclient                            } hitcount:         10
1420    { child_comm: emacs                               } hitcount:         12
1421    { child_comm: dbus-daemon                         } hitcount:         20
1422    { child_comm: nm-dispatcher.a                     } hitcount:         20
1423    { child_comm: evolution                           } hitcount:         35
1424    { child_comm: glib-pacrunner                      } hitcount:         59
1425
1426    Totals:
1427        Hits: 199
1428        Entries: 21
1429        Dropped: 0
1430
1431  To manually continue having the trigger aggregate events, append
1432  :cont instead.  Notice that the trigger info displays as [active]
1433  again, and the data has changed:
1434
1435    # echo 'hist:key=child_comm:val=hitcount:size=256:cont' >> \
1436           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
1437
1438    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1439    # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
1440
1441    { child_comm: dconf worker                        } hitcount:          1
1442    { child_comm: dconf worker                        } hitcount:          1
1443    { child_comm: kthreadd                            } hitcount:          1
1444    { child_comm: gdbus                               } hitcount:          1
1445    { child_comm: ibus-daemon                         } hitcount:          1
1446    { child_comm: Socket Thread                       } hitcount:          2
1447    { child_comm: evolution-alarm                     } hitcount:          2
1448    { child_comm: smbd                                } hitcount:          2
1449    { child_comm: whoopsie                            } hitcount:          3
1450    { child_comm: compiz                              } hitcount:          3
1451    { child_comm: evolution-sourc                     } hitcount:          4
1452    { child_comm: bash                                } hitcount:          5
1453    { child_comm: pool                                } hitcount:          5
1454    { child_comm: postgres                            } hitcount:          6
1455    { child_comm: firefox                             } hitcount:          8
1456    { child_comm: dhclient                            } hitcount:         11
1457    { child_comm: emacs                               } hitcount:         12
1458    { child_comm: dbus-daemon                         } hitcount:         22
1459    { child_comm: nm-dispatcher.a                     } hitcount:         22
1460    { child_comm: evolution                           } hitcount:         35
1461    { child_comm: glib-pacrunner                      } hitcount:         59
1462
1463    Totals:
1464        Hits: 206
1465        Entries: 21
1466        Dropped: 0
1467
1468  The previous example showed how to start and stop a hist trigger by
1469  appending 'pause' and 'continue' to the hist trigger command.  A
1470  hist trigger can also be started in a paused state by initially
1471  starting the trigger with ':pause' appended.  This allows you to
1472  start the trigger only when you're ready to start collecting data
1473  and not before.  For example, you could start the trigger in a
1474  paused state, then unpause it and do something you want to measure,
1475  then pause the trigger again when done.
1476
1477  Of course, doing this manually can be difficult and error-prone, but
1478  it is possible to automatically start and stop a hist trigger based
1479  on some condition, via the enable_hist and disable_hist triggers.
1480
1481  For example, suppose we wanted to take a look at the relative
1482  weights in terms of skb length for each callpath that leads to a
1483  netif_receieve_skb event when downloading a decent-sized file using
1484  wget.
1485
1486  First we set up an initially paused stacktrace trigger on the
1487  netif_receive_skb event:
1488
1489    # echo 'hist:key=stacktrace:vals=len:pause' > \
1490           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1491
1492  Next, we set up an 'enable_hist' trigger on the sched_process_exec
1493  event, with an 'if filename==/usr/bin/wget' filter.  The effect of
1494  this new trigger is that it will 'unpause' the hist trigger we just
1495  set up on netif_receive_skb if and only if it sees a
1496  sched_process_exec event with a filename of '/usr/bin/wget'.  When
1497  that happens, all netif_receive_skb events are aggregated into a
1498  hash table keyed on stacktrace:
1499
1500    # echo 'enable_hist:net:netif_receive_skb if filename==/usr/bin/wget' > \
1501           /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
1502
1503  The aggregation continues until the netif_receive_skb is paused
1504  again, which is what the following disable_hist event does by
1505  creating a similar setup on the sched_process_exit event, using the
1506  filter 'comm==wget':
1507
1508    # echo 'disable_hist:net:netif_receive_skb if comm==wget' > \
1509           /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
1510
1511  Whenever a process exits and the comm field of the disable_hist
1512  trigger filter matches 'comm==wget', the netif_receive_skb hist
1513  trigger is disabled.
1514
1515  The overall effect is that netif_receive_skb events are aggregated
1516  into the hash table for only the duration of the wget.  Executing a
1517  wget command and then listing the 'hist' file will display the
1518  output generated by the wget command:
1519
1520    $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
1521
1522    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1523    # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1524
1525    { stacktrace:
1526         __netif_receive_skb_core+0x46d/0x990
1527         __netif_receive_skb+0x18/0x60
1528         netif_receive_skb_internal+0x23/0x90
1529         napi_gro_receive+0xc8/0x100
1530         ieee80211_deliver_skb+0xd6/0x270 [mac80211]
1531         ieee80211_rx_handlers+0xccf/0x22f0 [mac80211]
1532         ieee80211_prepare_and_rx_handle+0x4e7/0xc40 [mac80211]
1533         ieee80211_rx+0x31d/0x900 [mac80211]
1534         iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
1535         iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
1536         iwl_pcie_irq_handler+0xe3c/0x12f0 [iwlwifi]
1537         irq_thread_fn+0x20/0x50
1538         irq_thread+0x11f/0x150
1539         kthread+0xd2/0xf0
1540         ret_from_fork+0x42/0x70
1541    } hitcount:         85  len:      28884
1542    { stacktrace:
1543         __netif_receive_skb_core+0x46d/0x990
1544         __netif_receive_skb+0x18/0x60
1545         netif_receive_skb_internal+0x23/0x90
1546         napi_gro_complete+0xa4/0xe0
1547         dev_gro_receive+0x23a/0x360
1548         napi_gro_receive+0x30/0x100
1549         ieee80211_deliver_skb+0xd6/0x270 [mac80211]
1550         ieee80211_rx_handlers+0xccf/0x22f0 [mac80211]
1551         ieee80211_prepare_and_rx_handle+0x4e7/0xc40 [mac80211]
1552         ieee80211_rx+0x31d/0x900 [mac80211]
1553         iwlagn_rx_reply_rx+0x3db/0x6f0 [iwldvm]
1554         iwl_rx_dispatch+0x8e/0xf0 [iwldvm]
1555         iwl_pcie_irq_handler+0xe3c/0x12f0 [iwlwifi]
1556         irq_thread_fn+0x20/0x50
1557         irq_thread+0x11f/0x150
1558         kthread+0xd2/0xf0
1559    } hitcount:         98  len:     664329
1560    { stacktrace:
1561         __netif_receive_skb_core+0x46d/0x990
1562         __netif_receive_skb+0x18/0x60
1563         process_backlog+0xa8/0x150
1564         net_rx_action+0x15d/0x340
1565         __do_softirq+0x114/0x2c0
1566         do_softirq_own_stack+0x1c/0x30
1567         do_softirq+0x65/0x70
1568         __local_bh_enable_ip+0xb5/0xc0
1569         ip_finish_output+0x1f4/0x840
1570         ip_output+0x6b/0xc0
1571         ip_local_out_sk+0x31/0x40
1572         ip_send_skb+0x1a/0x50
1573         udp_send_skb+0x173/0x2a0
1574         udp_sendmsg+0x2bf/0x9f0
1575         inet_sendmsg+0x64/0xa0
1576         sock_sendmsg+0x3d/0x50
1577    } hitcount:        115  len:      13030
1578    { stacktrace:
1579         __netif_receive_skb_core+0x46d/0x990
1580         __netif_receive_skb+0x18/0x60
1581         netif_receive_skb_internal+0x23/0x90
1582         napi_gro_complete+0xa4/0xe0
1583         napi_gro_flush+0x6d/0x90
1584         iwl_pcie_irq_handler+0x92a/0x12f0 [iwlwifi]
1585         irq_thread_fn+0x20/0x50
1586         irq_thread+0x11f/0x150
1587         kthread+0xd2/0xf0
1588         ret_from_fork+0x42/0x70
1589    } hitcount:        934  len:    5512212
1590
1591    Totals:
1592        Hits: 1232
1593        Entries: 4
1594        Dropped: 0
1595
1596  The above shows all the netif_receive_skb callpaths and their total
1597  lengths for the duration of the wget command.
1598
1599  The 'clear' hist trigger param can be used to clear the hash table.
1600  Suppose we wanted to try another run of the previous example but
1601  this time also wanted to see the complete list of events that went
1602  into the histogram.  In order to avoid having to set everything up
1603  again, we can just clear the histogram first:
1604
1605    # echo 'hist:key=stacktrace:vals=len:clear' >> \
1606           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1607
1608  Just to verify that it is in fact cleared, here's what we now see in
1609  the hist file:
1610
1611    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1612    # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1613
1614    Totals:
1615        Hits: 0
1616        Entries: 0
1617        Dropped: 0
1618
1619  Since we want to see the detailed list of every netif_receive_skb
1620  event occurring during the new run, which are in fact the same
1621  events being aggregated into the hash table, we add some additional
1622  'enable_event' events to the triggering sched_process_exec and
1623  sched_process_exit events as such:
1624
1625    # echo 'enable_event:net:netif_receive_skb if filename==/usr/bin/wget' > \
1626           /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
1627
1628    # echo 'disable_event:net:netif_receive_skb if comm==wget' > \
1629           /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
1630
1631  If you read the trigger files for the sched_process_exec and
1632  sched_process_exit triggers, you should see two triggers for each:
1633  one enabling/disabling the hist aggregation and the other
1634  enabling/disabling the logging of events:
1635
1636    # cat /sys/kernel/debug/tracing/events/sched/sched_process_exec/trigger
1637    enable_event:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
1638    enable_hist:net:netif_receive_skb:unlimited if filename==/usr/bin/wget
1639
1640    # cat /sys/kernel/debug/tracing/events/sched/sched_process_exit/trigger
1641    enable_event:net:netif_receive_skb:unlimited if comm==wget
1642    disable_hist:net:netif_receive_skb:unlimited if comm==wget
1643
1644  In other words, whenever either of the sched_process_exec or
1645  sched_process_exit events is hit and matches 'wget', it enables or
1646  disables both the histogram and the event log, and what you end up
1647  with is a hash table and set of events just covering the specified
1648  duration.  Run the wget command again:
1649
1650    $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
1651
1652  Displaying the 'hist' file should show something similar to what you
1653  saw in the last run, but this time you should also see the
1654  individual events in the trace file:
1655
1656    # cat /sys/kernel/debug/tracing/trace
1657
1658    # tracer: nop
1659    #
1660    # entries-in-buffer/entries-written: 183/1426   #P:4
1661    #
1662    #                              _-----=> irqs-off
1663    #                             / _----=> need-resched
1664    #                            | / _---=> hardirq/softirq
1665    #                            || / _--=> preempt-depth
1666    #                            ||| /     delay
1667    #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
1668    #              | |       |   ||||       |         |
1669                wget-15108 [000] ..s1 31769.606929: netif_receive_skb: dev=lo skbaddr=ffff88009c353100 len=60
1670                wget-15108 [000] ..s1 31769.606999: netif_receive_skb: dev=lo skbaddr=ffff88009c353200 len=60
1671             dnsmasq-1382  [000] ..s1 31769.677652: netif_receive_skb: dev=lo skbaddr=ffff88009c352b00 len=130
1672             dnsmasq-1382  [000] ..s1 31769.685917: netif_receive_skb: dev=lo skbaddr=ffff88009c352200 len=138
1673    ##### CPU 2 buffer started ####
1674      irq/29-iwlwifi-559   [002] ..s. 31772.031529: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433d00 len=2948
1675      irq/29-iwlwifi-559   [002] ..s. 31772.031572: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432200 len=1500
1676      irq/29-iwlwifi-559   [002] ..s. 31772.032196: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433100 len=2948
1677      irq/29-iwlwifi-559   [002] ..s. 31772.032761: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433000 len=2948
1678      irq/29-iwlwifi-559   [002] ..s. 31772.033220: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432e00 len=1500
1679    .
1680    .
1681    .
1682
1683  The following example demonstrates how multiple hist triggers can be
1684  attached to a given event.  This capability can be useful for
1685  creating a set of different summaries derived from the same set of
1686  events, or for comparing the effects of different filters, among
1687  other things.
1688
1689    # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
1690           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1691    # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
1692           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1693    # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
1694           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1695    # echo 'hist:keys=skbaddr.hex:vals=len' >> \
1696           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1697    # echo 'hist:keys=len:vals=common_preempt_count' >> \
1698           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1699
1700  The above set of commands create four triggers differing only in
1701  their filters, along with a completely different though fairly
1702  nonsensical trigger.  Note that in order to append multiple hist
1703  triggers to the same file, you should use the '>>' operator to
1704  append them ('>' will also add the new hist trigger, but will remove
1705  any existing hist triggers beforehand).
1706
1707  Displaying the contents of the 'hist' file for the event shows the
1708  contents of all five histograms:
1709
1710    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1711
1712    # event histogram
1713    #
1714    # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
1715    #
1716
1717    { len:        176 } hitcount:          1  common_preempt_count:          0
1718    { len:        223 } hitcount:          1  common_preempt_count:          0
1719    { len:       4854 } hitcount:          1  common_preempt_count:          0
1720    { len:        395 } hitcount:          1  common_preempt_count:          0
1721    { len:        177 } hitcount:          1  common_preempt_count:          0
1722    { len:        446 } hitcount:          1  common_preempt_count:          0
1723    { len:       1601 } hitcount:          1  common_preempt_count:          0
1724    .
1725    .
1726    .
1727    { len:       1280 } hitcount:         66  common_preempt_count:          0
1728    { len:        116 } hitcount:         81  common_preempt_count:         40
1729    { len:        708 } hitcount:        112  common_preempt_count:          0
1730    { len:         46 } hitcount:        221  common_preempt_count:          0
1731    { len:       1264 } hitcount:        458  common_preempt_count:          0
1732
1733    Totals:
1734        Hits: 1428
1735        Entries: 147
1736        Dropped: 0
1737
1738
1739    # event histogram
1740    #
1741    # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1742    #
1743
1744    { skbaddr: ffff8800baee5e00 } hitcount:          1  len:        130
1745    { skbaddr: ffff88005f3d5600 } hitcount:          1  len:       1280
1746    { skbaddr: ffff88005f3d4900 } hitcount:          1  len:       1280
1747    { skbaddr: ffff88009fed6300 } hitcount:          1  len:        115
1748    { skbaddr: ffff88009fe0ad00 } hitcount:          1  len:        115
1749    { skbaddr: ffff88008cdb1900 } hitcount:          1  len:         46
1750    { skbaddr: ffff880064b5ef00 } hitcount:          1  len:        118
1751    { skbaddr: ffff880044e3c700 } hitcount:          1  len:         60
1752    { skbaddr: ffff880100065900 } hitcount:          1  len:         46
1753    { skbaddr: ffff8800d46bd500 } hitcount:          1  len:        116
1754    { skbaddr: ffff88005f3d5f00 } hitcount:          1  len:       1280
1755    { skbaddr: ffff880100064700 } hitcount:          1  len:        365
1756    { skbaddr: ffff8800badb6f00 } hitcount:          1  len:         60
1757    .
1758    .
1759    .
1760    { skbaddr: ffff88009fe0be00 } hitcount:         27  len:      24677
1761    { skbaddr: ffff88009fe0a400 } hitcount:         27  len:      23052
1762    { skbaddr: ffff88009fe0b700 } hitcount:         31  len:      25589
1763    { skbaddr: ffff88009fe0b600 } hitcount:         32  len:      27326
1764    { skbaddr: ffff88006a462800 } hitcount:         68  len:      71678
1765    { skbaddr: ffff88006a463700 } hitcount:         70  len:      72678
1766    { skbaddr: ffff88006a462b00 } hitcount:         71  len:      77589
1767    { skbaddr: ffff88006a463600 } hitcount:         73  len:      71307
1768    { skbaddr: ffff88006a462200 } hitcount:         81  len:      81032
1769
1770    Totals:
1771        Hits: 1451
1772        Entries: 318
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 == 256 [active]
1779    #
1780
1781
1782    Totals:
1783        Hits: 0
1784        Entries: 0
1785        Dropped: 0
1786
1787
1788    # event histogram
1789    #
1790    # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [active]
1791    #
1792
1793    { skbaddr: ffff88009fd2c300 } hitcount:          1  len:       7212
1794    { skbaddr: ffff8800d2bcce00 } hitcount:          1  len:       7212
1795    { skbaddr: ffff8800d2bcd700 } hitcount:          1  len:       7212
1796    { skbaddr: ffff8800d2bcda00 } hitcount:          1  len:      21492
1797    { skbaddr: ffff8800ae2e2d00 } hitcount:          1  len:       7212
1798    { skbaddr: ffff8800d2bcdb00 } hitcount:          1  len:       7212
1799    { skbaddr: ffff88006a4df500 } hitcount:          1  len:       4854
1800    { skbaddr: ffff88008ce47b00 } hitcount:          1  len:      18636
1801    { skbaddr: ffff8800ae2e2200 } hitcount:          1  len:      12924
1802    { skbaddr: ffff88005f3e1000 } hitcount:          1  len:       4356
1803    { skbaddr: ffff8800d2bcdc00 } hitcount:          2  len:      24420
1804    { skbaddr: ffff8800d2bcc200 } hitcount:          2  len:      12996
1805
1806    Totals:
1807        Hits: 14
1808        Entries: 12
1809        Dropped: 0
1810
1811
1812    # event histogram
1813    #
1814    # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
1815    #
1816
1817
1818    Totals:
1819        Hits: 0
1820        Entries: 0
1821        Dropped: 0
1822
1823  Named triggers can be used to have triggers share a common set of
1824  histogram data.  This capability is mostly useful for combining the
1825  output of events generated by tracepoints contained inside inline
1826  functions, but names can be used in a hist trigger on any event.
1827  For example, these two triggers when hit will update the same 'len'
1828  field in the shared 'foo' histogram data:
1829
1830    # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1831           /sys/kernel/debug/tracing/events/net/netif_receive_skb/trigger
1832    # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1833           /sys/kernel/debug/tracing/events/net/netif_rx/trigger
1834
1835  You can see that they're updating common histogram data by reading
1836  each event's hist files at the same time:
1837
1838    # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist;
1839      cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1840
1841    # event histogram
1842    #
1843    # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1844    #
1845
1846    { skbaddr: ffff88000ad53500 } hitcount:          1  len:         46
1847    { skbaddr: ffff8800af5a1500 } hitcount:          1  len:         76
1848    { skbaddr: ffff8800d62a1900 } hitcount:          1  len:         46
1849    { skbaddr: ffff8800d2bccb00 } hitcount:          1  len:        468
1850    { skbaddr: ffff8800d3c69900 } hitcount:          1  len:         46
1851    { skbaddr: ffff88009ff09100 } hitcount:          1  len:         52
1852    { skbaddr: ffff88010f13ab00 } hitcount:          1  len:        168
1853    { skbaddr: ffff88006a54f400 } hitcount:          1  len:         46
1854    { skbaddr: ffff8800d2bcc500 } hitcount:          1  len:        260
1855    { skbaddr: ffff880064505000 } hitcount:          1  len:         46
1856    { skbaddr: ffff8800baf24e00 } hitcount:          1  len:         32
1857    { skbaddr: ffff88009fe0ad00 } hitcount:          1  len:         46
1858    { skbaddr: ffff8800d3edff00 } hitcount:          1  len:         44
1859    { skbaddr: ffff88009fe0b400 } hitcount:          1  len:        168
1860    { skbaddr: ffff8800a1c55a00 } hitcount:          1  len:         40
1861    { skbaddr: ffff8800d2bcd100 } hitcount:          1  len:         40
1862    { skbaddr: ffff880064505f00 } hitcount:          1  len:        174
1863    { skbaddr: ffff8800a8bff200 } hitcount:          1  len:        160
1864    { skbaddr: ffff880044e3cc00 } hitcount:          1  len:         76
1865    { skbaddr: ffff8800a8bfe700 } hitcount:          1  len:         46
1866    { skbaddr: ffff8800d2bcdc00 } hitcount:          1  len:         32
1867    { skbaddr: ffff8800a1f64800 } hitcount:          1  len:         46
1868    { skbaddr: ffff8800d2bcde00 } hitcount:          1  len:        988
1869    { skbaddr: ffff88006a5dea00 } hitcount:          1  len:         46
1870    { skbaddr: ffff88002e37a200 } hitcount:          1  len:         44
1871    { skbaddr: ffff8800a1f32c00 } hitcount:          2  len:        676
1872    { skbaddr: ffff88000ad52600 } hitcount:          2  len:        107
1873    { skbaddr: ffff8800a1f91e00 } hitcount:          2  len:         92
1874    { skbaddr: ffff8800af5a0200 } hitcount:          2  len:        142
1875    { skbaddr: ffff8800d2bcc600 } hitcount:          2  len:        220
1876    { skbaddr: ffff8800ba36f500 } hitcount:          2  len:         92
1877    { skbaddr: ffff8800d021f800 } hitcount:          2  len:         92
1878    { skbaddr: ffff8800a1f33600 } hitcount:          2  len:        675
1879    { skbaddr: ffff8800a8bfff00 } hitcount:          3  len:        138
1880    { skbaddr: ffff8800d62a1300 } hitcount:          3  len:        138
1881    { skbaddr: ffff88002e37a100 } hitcount:          4  len:        184
1882    { skbaddr: ffff880064504400 } hitcount:          4  len:        184
1883    { skbaddr: ffff8800a8bfec00 } hitcount:          4  len:        184
1884    { skbaddr: ffff88000ad53700 } hitcount:          5  len:        230
1885    { skbaddr: ffff8800d2bcdb00 } hitcount:          5  len:        196
1886    { skbaddr: ffff8800a1f90000 } hitcount:          6  len:        276
1887    { skbaddr: ffff88006a54f900 } hitcount:          6  len:        276
1888
1889    Totals:
1890        Hits: 81
1891        Entries: 42
1892        Dropped: 0
1893    # event histogram
1894    #
1895    # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1896    #
1897
1898    { skbaddr: ffff88000ad53500 } hitcount:          1  len:         46
1899    { skbaddr: ffff8800af5a1500 } hitcount:          1  len:         76
1900    { skbaddr: ffff8800d62a1900 } hitcount:          1  len:         46
1901    { skbaddr: ffff8800d2bccb00 } hitcount:          1  len:        468
1902    { skbaddr: ffff8800d3c69900 } hitcount:          1  len:         46
1903    { skbaddr: ffff88009ff09100 } hitcount:          1  len:         52
1904    { skbaddr: ffff88010f13ab00 } hitcount:          1  len:        168
1905    { skbaddr: ffff88006a54f400 } hitcount:          1  len:         46
1906    { skbaddr: ffff8800d2bcc500 } hitcount:          1  len:        260
1907    { skbaddr: ffff880064505000 } hitcount:          1  len:         46
1908    { skbaddr: ffff8800baf24e00 } hitcount:          1  len:         32
1909    { skbaddr: ffff88009fe0ad00 } hitcount:          1  len:         46
1910    { skbaddr: ffff8800d3edff00 } hitcount:          1  len:         44
1911    { skbaddr: ffff88009fe0b400 } hitcount:          1  len:        168
1912    { skbaddr: ffff8800a1c55a00 } hitcount:          1  len:         40
1913    { skbaddr: ffff8800d2bcd100 } hitcount:          1  len:         40
1914    { skbaddr: ffff880064505f00 } hitcount:          1  len:        174
1915    { skbaddr: ffff8800a8bff200 } hitcount:          1  len:        160
1916    { skbaddr: ffff880044e3cc00 } hitcount:          1  len:         76
1917    { skbaddr: ffff8800a8bfe700 } hitcount:          1  len:         46
1918    { skbaddr: ffff8800d2bcdc00 } hitcount:          1  len:         32
1919    { skbaddr: ffff8800a1f64800 } hitcount:          1  len:         46
1920    { skbaddr: ffff8800d2bcde00 } hitcount:          1  len:        988
1921    { skbaddr: ffff88006a5dea00 } hitcount:          1  len:         46
1922    { skbaddr: ffff88002e37a200 } hitcount:          1  len:         44
1923    { skbaddr: ffff8800a1f32c00 } hitcount:          2  len:        676
1924    { skbaddr: ffff88000ad52600 } hitcount:          2  len:        107
1925    { skbaddr: ffff8800a1f91e00 } hitcount:          2  len:         92
1926    { skbaddr: ffff8800af5a0200 } hitcount:          2  len:        142
1927    { skbaddr: ffff8800d2bcc600 } hitcount:          2  len:        220
1928    { skbaddr: ffff8800ba36f500 } hitcount:          2  len:         92
1929    { skbaddr: ffff8800d021f800 } hitcount:          2  len:         92
1930    { skbaddr: ffff8800a1f33600 } hitcount:          2  len:        675
1931    { skbaddr: ffff8800a8bfff00 } hitcount:          3  len:        138
1932    { skbaddr: ffff8800d62a1300 } hitcount:          3  len:        138
1933    { skbaddr: ffff88002e37a100 } hitcount:          4  len:        184
1934    { skbaddr: ffff880064504400 } hitcount:          4  len:        184
1935    { skbaddr: ffff8800a8bfec00 } hitcount:          4  len:        184
1936    { skbaddr: ffff88000ad53700 } hitcount:          5  len:        230
1937    { skbaddr: ffff8800d2bcdb00 } hitcount:          5  len:        196
1938    { skbaddr: ffff8800a1f90000 } hitcount:          6  len:        276
1939    { skbaddr: ffff88006a54f900 } hitcount:          6  len:        276
1940
1941    Totals:
1942        Hits: 81
1943        Entries: 42
1944        Dropped: 0
1945
1946  And here's an example that shows how to combine histogram data from
1947  any two events even if they don't share any 'compatible' fields
1948  other than 'hitcount' and 'stacktrace'.  These commands create a
1949  couple of triggers named 'bar' using those fields:
1950
1951    # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1952           /sys/kernel/debug/tracing/events/sched/sched_process_fork/trigger
1953    # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1954          /sys/kernel/debug/tracing/events/net/netif_rx/trigger
1955
1956  And displaying the output of either shows some interesting if
1957  somewhat confusing output:
1958
1959    # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1960    # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1961
1962    # event histogram
1963    #
1964    # trigger info: hist:name=bar:keys=stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
1965    #
1966
1967    { stacktrace:
1968             _do_fork+0x18e/0x330
1969             kernel_thread+0x29/0x30
1970             kthreadd+0x154/0x1b0
1971             ret_from_fork+0x3f/0x70
1972    } hitcount:          1
1973    { stacktrace:
1974             netif_rx_internal+0xb2/0xd0
1975             netif_rx_ni+0x20/0x70
1976             dev_loopback_xmit+0xaa/0xd0
1977             ip_mc_output+0x126/0x240
1978             ip_local_out_sk+0x31/0x40
1979             igmp_send_report+0x1e9/0x230
1980             igmp_timer_expire+0xe9/0x120
1981             call_timer_fn+0x39/0xf0
1982             run_timer_softirq+0x1e1/0x290
1983             __do_softirq+0xfd/0x290
1984             irq_exit+0x98/0xb0
1985             smp_apic_timer_interrupt+0x4a/0x60
1986             apic_timer_interrupt+0x6d/0x80
1987             cpuidle_enter+0x17/0x20
1988             call_cpuidle+0x3b/0x60
1989             cpu_startup_entry+0x22d/0x310
1990    } hitcount:          1
1991    { stacktrace:
1992             netif_rx_internal+0xb2/0xd0
1993             netif_rx_ni+0x20/0x70
1994             dev_loopback_xmit+0xaa/0xd0
1995             ip_mc_output+0x17f/0x240
1996             ip_local_out_sk+0x31/0x40
1997             ip_send_skb+0x1a/0x50
1998             udp_send_skb+0x13e/0x270
1999             udp_sendmsg+0x2bf/0x980
2000             inet_sendmsg+0x67/0xa0
2001             sock_sendmsg+0x38/0x50
2002             SYSC_sendto+0xef/0x170
2003             SyS_sendto+0xe/0x10
2004             entry_SYSCALL_64_fastpath+0x12/0x6a
2005    } hitcount:          2
2006    { stacktrace:
2007             netif_rx_internal+0xb2/0xd0
2008             netif_rx+0x1c/0x60
2009             loopback_xmit+0x6c/0xb0
2010             dev_hard_start_xmit+0x219/0x3a0
2011             __dev_queue_xmit+0x415/0x4f0
2012             dev_queue_xmit_sk+0x13/0x20
2013             ip_finish_output2+0x237/0x340
2014             ip_finish_output+0x113/0x1d0
2015             ip_output+0x66/0xc0
2016             ip_local_out_sk+0x31/0x40
2017             ip_send_skb+0x1a/0x50
2018             udp_send_skb+0x16d/0x270
2019             udp_sendmsg+0x2bf/0x980
2020             inet_sendmsg+0x67/0xa0
2021             sock_sendmsg+0x38/0x50
2022             ___sys_sendmsg+0x14e/0x270
2023    } hitcount:         76
2024    { stacktrace:
2025             netif_rx_internal+0xb2/0xd0
2026             netif_rx+0x1c/0x60
2027             loopback_xmit+0x6c/0xb0
2028             dev_hard_start_xmit+0x219/0x3a0
2029             __dev_queue_xmit+0x415/0x4f0
2030             dev_queue_xmit_sk+0x13/0x20
2031             ip_finish_output2+0x237/0x340
2032             ip_finish_output+0x113/0x1d0
2033             ip_output+0x66/0xc0
2034             ip_local_out_sk+0x31/0x40
2035             ip_send_skb+0x1a/0x50
2036             udp_send_skb+0x16d/0x270
2037             udp_sendmsg+0x2bf/0x980
2038             inet_sendmsg+0x67/0xa0
2039             sock_sendmsg+0x38/0x50
2040             ___sys_sendmsg+0x269/0x270
2041    } hitcount:         77
2042    { stacktrace:
2043             netif_rx_internal+0xb2/0xd0
2044             netif_rx+0x1c/0x60
2045             loopback_xmit+0x6c/0xb0
2046             dev_hard_start_xmit+0x219/0x3a0
2047             __dev_queue_xmit+0x415/0x4f0
2048             dev_queue_xmit_sk+0x13/0x20
2049             ip_finish_output2+0x237/0x340
2050             ip_finish_output+0x113/0x1d0
2051             ip_output+0x66/0xc0
2052             ip_local_out_sk+0x31/0x40
2053             ip_send_skb+0x1a/0x50
2054             udp_send_skb+0x16d/0x270
2055             udp_sendmsg+0x2bf/0x980
2056             inet_sendmsg+0x67/0xa0
2057             sock_sendmsg+0x38/0x50
2058             SYSC_sendto+0xef/0x170
2059    } hitcount:         88
2060    { stacktrace:
2061             _do_fork+0x18e/0x330
2062             SyS_clone+0x19/0x20
2063             entry_SYSCALL_64_fastpath+0x12/0x6a
2064    } hitcount:        244
2065
2066    Totals:
2067        Hits: 489
2068        Entries: 7
2069        Dropped: 0
2070
lxr.linux.no kindly hosted by Redpill Linpro AS, provider of Linux consulting and operations services since 1995.