lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-Id: <cover.1628807056.git.zanussi@kernel.org>
Date:   Thu, 12 Aug 2021 17:43:23 -0500
From:   Tom Zanussi <zanussi@...nel.org>
To:     rostedt@...dmis.org, bristot@...nel.org
Cc:     mhiramat@...nel.org, linux-kernel@...r.kernel.org,
        linux-rt-users@...r.kernel.org
Subject: [PATCH 0/1] tracing: Provide more parseable hist trigger output

Hi Steve and Daniel,

Following our discussion last week about more parseable hist trigger
output, I started trying to implement the 'csv' output you had
mentioned, but realized that since it was more than just table output
that was needed, JSON would be a better fit, so implemented that in
this patch instead.

I designed it so that more files/formats could be easily added as
desired, so if you still want the csv output, let me know.  If so,
though, please give me some more detailed idea as to what you think
that should look like.

Here are some examples of the JSON output for various histograms:

A simple straighforward histogram:

  # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' >> /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger

  # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist_json

[
  "hist":{
    "info":{
      "trigger":"hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:size=2048 [active]
"
    },
    "map":{
      "entry":{
        "keys":[
          {
            "id":"sys_read                      [  0]",
          },
          {
            "common_pid":"Xwayland        [      2867]",
          },
        ],
        "vals":[
          {
            "hitcount":"1",
          },
        ],
      },
      "entry":{
        "keys":[
          {
            "id":"sys_read                      [  0]",
          },
          {
            "common_pid":"sh              [      3428]",
          },
        ],
        "vals":[
          {
            "hitcount":"1",
          },
        ],
      },
      "entry":{
  ...
      "entry":{
        "keys":[
          {
            "id":"sys_getrandom                 [318]",
          },
          {
            "common_pid":"update-notifier [      3408]",
          },
        ],
        "vals":[
          {
            "hitcount":"95",
          },
        ],
      },
      "entry":{
        "keys":[
          {
            "id":"sys_getrandom                 [318]",
          },
          {
            "common_pid":"apt-check       [      3416]",
          },
        ],
        "vals":[
          {
            "hitcount":"815",
          },
        ],
      },
    },
    "totals":{
      "hits":"112930",
      "entries":"1390",
      "dropped":"0",
    },
  },
]


A histogram with save() variables and snapshot() info:

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"' >> /sys/kernel/debug/tracing/events/sched/sched_waking/trigger

  #echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio,prev_comm):onmax($wakeup_lat).snapshot() if next_comm=="cyclictest"' >> /sys/kernel/debug/tracing/events/sched/sched_switch/trigger

  # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist_json

[
  "hist":{
    "info":{
      "trigger":"hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio,prev_comm):onmax($wakeup_lat).snapshot() if next_comm=="cyclictest" [active]
"
    },
    "map":{
      "entry":{
        "keys":[
          {
            "next_pid":"3419",
          },
        ],
        "vals":[
          {
            "hitcount":"156",
          },
        ],
        "action":{
          "max":"439",
          "next_prio":"120",
          "next_comm":"cyclictest",
          "prev_pid":"0",
          "prev_prio":"120",
          "prev_comm":"swapper/1",
        },
      },
      "entry":{
        "keys":[
          {
            "next_pid":"3420",
          },
        ],
        "vals":[
          {
            "hitcount":"1563",
          },
        ],
        "action":{
          "max":"1667",
          "next_prio":"120",
          "next_comm":"cyclictest",
          "prev_pid":"1991",
          "prev_prio":"120",
          "prev_comm":"FAHClient",
        },
      },
    },
    "snapshot":{
      "handler":"onmax",
      "$wakeup_lat":"1667",
      "keys":[
        {
          "next_pid":"3420",
        },
      ],
    },
    "totals":{
      "hits":"1719",
      "entries":"2",
      "dropped":"0",
    },
  },
]

And finally, just to show that even stacktraces in JSON works ;-)

  # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' >> /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

  # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist_json 

    "info":{
      "trigger":"hist:keys=stacktrace:vals=hitcount,bytes_req,bytes_alloc:sort=b
ytes_alloc:size=2048 [active]
"
    },
    "map":{
      "entry":{
        "keys":[
          {
            "stacktrace":"
            acpi_ns_internalize_name+0x4a/0xa3
            acpi_ns_get_node_unlocked+0x70/0xd8
            acpi_ns_get_node+0x40/0x55
            acpi_ns_evaluate+0x4c/0x24e
            acpi_evaluate_object+0x137/0x240
            acpi_battery_get_state+0x95/0x230
            acpi_battery_get_property+0x4c/0x3f0
            power_supply_show_property+0xd2/0x260
            dev_attr_show+0x18/0x50
            sysfs_kf_seq_show+0xa3/0x110
            seq_read_iter+0xdd/0x460
            new_sync_read+0x11b/0x1a0
            vfs_read+0x198/0x1c0
            ksys_read+0xa7/0xe0
            do_syscall_64+0x3a/0xb0
            entry_SYSCALL_64_after_hwframe+0x44/0xae
            "
          },
        ],
        "vals":[
          {
            "hitcount":"1",
          },
          {
            "bytes_req":"8",
          },
          {
            "bytes_alloc":"8",
          },
          },
        ],
      },
      "entry":{
        "keys":[
          {
            "stacktrace":"
            ecryptfs_write_inode_size_to_metadata+0x38/0x190
            truncate_upper.isra.16+0x14e/0x250
            ecryptfs_setattr+0x276/0x2c0
            notify_change+0x392/0x4d0
            do_truncate+0x7c/0xd0
            path_openat+0x8e2/0xa60
            do_filp_open+0xc5/0x140
            do_sys_openat2+0x23e/0x300
            do_sys_open+0x57/0x80
            do_syscall_64+0x3a/0xb0
            entry_SYSCALL_64_after_hwframe+0x44/0xae
            "
          },
        ],
        "vals":[
          {
            "hitcount":"1",
          },
          {
            "bytes_req":"8",
          },
          {
            "bytes_alloc":"8",
          },
        ],
      },
  ...
      "entry":{
        "keys":[
          {
            "stacktrace":"
            ath10k_wmi_tlv_parse_alloc.constprop.30+0x35/0x80 [ath10k_core]
            ath10k_wmi_tlv_op_pull_fw_stats+0x38/0x420 [ath10k_core]
            ath10k_debug_fw_stats_process+0x9c/0x410 [ath10k_core]
            ath10k_wmi_tlv_op_rx+0x1a6/0xf20 [ath10k_core]
            ath10k_htc_rx_completion_handler+0x13c/0x180 [ath10k_core]
            ath10k_pci_process_rx_cb+0x122/0x190 [ath10k_pci]
            ath10k_ce_per_engine_service+0x5d/0x80 [ath10k_core]
            ath10k_ce_per_engine_service_any+0x6a/0xa0 [ath10k_core]
            ath10k_pci_napi_poll+0x44/0x110 [ath10k_pci]
            __napi_poll+0x2d/0x200
            net_rx_action+0xe6/0x210
            __do_softirq+0xce/0x43c
            irq_exit_rcu+0xa4/0xb0
            common_interrupt+0x5c/0xa0
            asm_common_interrupt+0x1e/0x40
            cpuidle_enter_state+0x113/0x4a0
            "
          },
        ],
        "vals":[
          {
            "hitcount":"569",
          },
          {
            "bytes_req":"3149984",
          },
          {
            "bytes_alloc":"4661248",
          },
        ],
      },
    },
    "totals":{
      "hits":"62147",
      "entries":"453",
      "dropped":"0",
    },
  },
]

Tom

The following changes since commit 3dc65994e3c1c999be3d991cdc96705e167cb3b1:

  tools/bootconfig: Use per-group/all enable option in ftrace2bconf script (2021-08-08 19:41:50 -0400)

are available in the Git repository at:

  git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace/hist-json-v1

Tom Zanussi (1):
  tracing: Add hist_json event file

 kernel/trace/trace.h             |   1 +
 kernel/trace/trace_events.c      |   2 +
 kernel/trace/trace_events_hist.c | 532 ++++++++++++++++++++++++++-----
 3 files changed, 463 insertions(+), 72 deletions(-)

-- 
2.17.1

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ