SQLHIST(1)
🦋 sqlhist 🦋
okay so real talk, this page comes from the libtracefs Manual and it's section 1, and bestie… it's genuinely a whole vibe. it's the little tool that turns your SQL dreams into actual kernel tracing reality. let's get into it 💅
✨ NAME ✨
sqlhist — the tool that uses SQL language to create tracefs histograms and synthetic events, and also to show you the creation commands it just made. it's giving translator, it's giving middle-management-for-the-kernel 💖
🌸 SYNOPSIS 🌸
sqlhist [OPTIONS] [SQL-select-command]🎀 DESCRIPTION 🎀
okay so sqlhist(1) takes an SQL-like statement and uses it to create tracefs histograms and synthetic events — the kind that can perform a whole bunch of actions for a whole bunch of different ways of handling your data. she's versatile, periodt ✨
the tracefs filesystem is what interfaces with the Linux tracing infrastructure, which has all these dynamic and static events scattered throughout the kernel. and every single one of those events can have a "histogram" attached to it — the fields of the event are literally what define the buckets of that histogram. no cap, the event's own fields are the vibe check 🪣
now, a synthetic event is a whole different creature: it's a way of attaching two separate events together and using the fields and time stamps of those two events to build a brand new dynamic event. that new dynamic event? yeah, that's what we call a synthetic event. and the fields of each event can have simple calculations done on them — for example, you can take the delta between a field of one event and a field of the other event. it works for the time stamps too, bestie: the time delta between the two events can be extracted and dropped right into the synthetic event. math but make it ✨tracing✨
other actions can be done from the fields of the events as well. a snapshot can be taken of the kernel ring buffer — either when a variable used in the synthetic event creation hits a max, or when it simply changes. like a screenshot but for your kernel 📸
here's the thing though: the commands to create histograms and synthetic events are complex and genuinely not easy to remember. that's literally the entire reason sqlhist exists — it converts SQL syntax into the commands you actually need to create the histogram or the synthetic event. she does the remembering so you don't have to 🧠💅
the SQL-select-command is a SQL string defined by tracefs_sql(3). that's the spec, go read it, iykyk.
ngl this one matters: you gotta run this as root (or with sudo), because interacting with the tracefs directory requires root privilege. unless you pass the -t option with a copy of the tracefs directory and its events — then you can play around without the big scary privileges 🫶
and fun fact: sqlhist is a simple program — its code actually exists inside the tracefs_sql(3) man page itself. the whole thing. iconic behavior honestly 👑
💜 OPTIONS 💜
-nname — the name of the synthetic event to create. once it exists, this event can be used like any other event and enabled viatrace-cmd(1). name her and she's yours 🎀-ttracefs-dir — okay so if you wanna test this out as a non-root user, you can use a copy of the tracefs directory, and passing that directory with this option lets the program actually work. obviously,-ewill not work as non-root because it won't be able to execute. sad but true 😭
# mkdir /tmp/tracing
# cp -r /sys/kernel/tracing/events /tmp/tracing
# exit
$ ./sqlhist -t /tmp/tracing ...-e— not only display the commands to create the histogram, but also execute them. this requires root privilege. she doesn't just talk about it, she does it 💅-ffile — instead of reading the SQL commands from the command line, read them from file. and if file is-then read from standard input. stdin girlies rise 🫶-mvar — do the given action when the variable var hits a new maximum. this can not be used with-c. pick a lane bestie 💀-cvar — do the given action when the variable var changes its value. this can not be used with-m. same energy, opposite lane 🌈-s— perform a snapshot instead of calling the synthetic event. 📸-T— perform both a snapshot and trace the synthetic event. why choose, right? have both, you deserve it ✨-Sfields[,fields] — save the given fields. heads up: the fields must be fields of the "end" event given in the SQL-select-command. read the room, not just any field will do 🙈-Binstance — for simple statements that only produce a histogram, the instance given here is where the histogram will be created. but this gets ignored for full synthetic event creation, because synthetic events have a global affect on all tracing instances, whereas histograms only affect a single instance. scope matters, bestie 💜
🔥 EXAMPLES 🔥
first up, create the sqlhist executable:
man tracefs_sql | sed -ne '/^EXAMPLE/,/FILES/ { /EXAMPLE/d ; /FILES/d ; p}' > sqlhist.c
gcc -o sqlhist sqlhist.c `pkg-config --cflags --libs libtracefs`and as described above, for testing purposes, make a copy of the event directory:
$ mkdir /tmp/tracing
$ sudo cp -r /sys/kernel/tracing/events /tmp/tracing/
$ sudo chmod -R 0644 /tmp/tracing/okay now for an example of simple histogram output using that copy of the tracefs directory:
$ ./sqlhist -t /tmp/tracing/ 'SELECT CAST(call_site as SYM-OFFSET), bytes_req, CAST(bytes_alloc AS _COUNTER_) FROM kmalloc'which produces this output:
echo 'hist:keys=call_site.sym-offset,bytes_req:vals=bytes_alloc' > /sys/kernel/tracing/events/kmem/kmalloc/triggerand that output could be used by root, like this:
# echo 'hist:keys=call_site.sym-offset,bytes_req:vals=bytes_alloc' > /sys/kernel/tracing/events/kmem/kmalloc/trigger
# cat /sys/kernel/tracing/events/kmem/kmalloc/hist
# event histogram
#
# trigger info: hist:keys=call_site.sym-offset,bytes_req:vals=hitcount,bytes_alloc:sort=hitcount:size=2048 [active]
#
{ call_site: [ffffffff813f8d8a] load_elf_phdrs+0x4a/0xb0 , bytes_req: 728 } hitcount: 1 bytes_alloc: 1024
{ call_site: [ffffffffc0c69e74] nf_ct_ext_add+0xd4/0x1d0 [nf_conntrack] , bytes_req: 128 } hitcount: 1 bytes_alloc: 128
{ call_site: [ffffffff818355e6] dma_resv_get_fences+0xf6/0x440 , bytes_req: 8 } hitcount: 1 bytes_alloc: 8
{ call_site: [ffffffffc06dc73f] intel_gt_get_buffer_pool+0x15f/0x290 [i915] , bytes_req: 424 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffff813f8d8a] load_elf_phdrs+0x4a/0xb0 , bytes_req: 616 } hitcount: 1 bytes_alloc: 1024
{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180 , bytes_req: 32 } hitcount: 1 bytes_alloc: 32
{ call_site: [ffffffffc070749d] shmem_get_pages+0xad/0x5d0 [i915] , bytes_req: 16 } hitcount: 1 bytes_alloc: 16
{ call_site: [ffffffffc07507f5] intel_framebuffer_create+0x25/0x60 [i915] , bytes_req: 408 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffffc06fc20f] eb_parse+0x34f/0x910 [i915] , bytes_req: 408 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffffc0700ebd] i915_gem_object_get_pages_internal+0x5d/0x270 [i915] , bytes_req: 16 } hitcount: 1 bytes_alloc: 16
{ call_site: [ffffffffc0771188] intel_frontbuffer_get+0x38/0x220 [i915] , bytes_req: 400 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180 , bytes_req: 128 } hitcount: 1 bytes_alloc: 128
{ call_site: [ffffffff813f8f45] load_elf_binary+0x155/0x1680 , bytes_req: 28 } hitcount: 1 bytes_alloc: 32
{ call_site: [ffffffffc07038c8] __assign_mmap_offset+0x208/0x3d0 [i915] , bytes_req: 288 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffff813737b2] alloc_bprm+0x32/0x2f0 , bytes_req: 416 } hitcount: 1 bytes_alloc: 512
{ call_site: [ffffffff813f9027] load_elf_binary+0x237/0x1680 , bytes_req: 64 } hitcount: 1 bytes_alloc: 64
{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180 , bytes_req: 64 } hitcount: 1 bytes_alloc: 64
{ call_site: [ffffffffc040ffe7] drm_vma_node_allow+0x27/0xe0 [drm] , bytes_req: 40 } hitcount: 2 bytes_alloc: 128
{ call_site: [ffffffff813cda98] __do_sys_timerfd_create+0x58/0x1c0 , bytes_req: 336 } hitcount: 2 bytes_alloc: 1024
{ call_site: [ffffffff818355e6] dma_resv_get_fences+0xf6/0x440 , bytes_req: 40 } hitcount: 2 bytes_alloc: 128
{ call_site: [ffffffff8139b75a] single_open+0x2a/0xa0 , bytes_req: 32 } hitcount: 2 bytes_alloc: 64
{ call_site: [ffffffff815df715] bio_kmalloc+0x25/0x80 , bytes_req: 136 } hitcount: 2 bytes_alloc: 384
{ call_site: [ffffffffc071e5cd] i915_vma_work+0x1d/0x50 [i915] , bytes_req: 416 } hitcount: 3 bytes_alloc: 1536
{ call_site: [ffffffff81390d0d] alloc_fdtable+0x4d/0x100 , bytes_req: 56 } hitcount: 3 bytes_alloc: 192
{ call_site: [ffffffffc06ff65f] i915_gem_do_execbuffer+0x158f/0x2440 [i915] , bytes_req: 16 } hitcount: 4 bytes_alloc: 64
{ call_site: [ffffffff8137713c] alloc_pipe_info+0x5c/0x230 , bytes_req: 384 } hitcount: 5 bytes_alloc: 2560
{ call_site: [ffffffff813771b4] alloc_pipe_info+0xd4/0x230 , bytes_req: 640 } hitcount: 5 bytes_alloc: 5120
{ call_site: [ffffffff81834cdb] dma_resv_list_alloc+0x1b/0x40 , bytes_req: 40 } hitcount: 6 bytes_alloc: 384
{ call_site: [ffffffff81834cdb] dma_resv_list_alloc+0x1b/0x40 , bytes_req: 56 } hitcount: 9 bytes_alloc: 576
{ call_site: [ffffffff8120086e] tracing_map_sort_entries+0x9e/0x3e0 , bytes_req: 24 } hitcount: 60 bytes_alloc: 1920
Totals:
Hits: 122
Entries: 30
Dropped: 0look at all those hits bestie. 122 of them. she ate 💅
one little note: even though the examples use uppercase for the SQL keywords, they do not have to be.SELECTcould also beselector evensElEcT. case is not the moment, the chaos is welcome 🌈
and by using the full SQL language, synthetic events can be made and processed. for example: using sqlhist along with trace-cmd(1), wake up latency can be recorded by creating a synthetic event that attaches the sched_waking and the sched_switch events. two events, one synthetic baby, and suddenly you're measuring latency like a main character 👑
# sqlhist -n wakeup_lat -e -T -m lat 'SELECT end.next_comm AS comm, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat FROM ' \
'sched_waking AS start JOIN sched_switch AS end ON start.pid = end.next_pid WHERE end.next_prio < 100 && end.next_comm == "cyclictest"'
# trace-cmd start -e all -e wakeup_lat -R stacktrace
# cyclictest -l 1000 -p80 -i250 -a -t -q -m -d 0 -b 1000 --tracemark
# trace-cmd show -s | tail -30
<idle>-0 [002] dNh4 23454.902246: sched_wakeup: comm=cyclictest pid=12272 prio=120 target_cpu=002
<idle>-0 [005] ...1 23454.902246: cpu_idle: state=4294967295 cpu_id=5
<idle>-0 [007] d..1 23454.902246: cpu_idle: state=0 cpu_id=7
<idle>-0 [002] dNh1 23454.902247: hrtimer_expire_exit: hrtimer=0000000037956dc2
<idle>-0 [005] d..1 23454.902248: cpu_idle: state=0 cpu_id=5
<idle>-0 [002] dNh1 23454.902248: write_msr: 6e0, value 4866ce957272
<idle>-0 [006] ...1 23454.902248: cpu_idle: state=4294967295 cpu_id=6
<idle>-0 [002] dNh1 23454.902249: local_timer_exit: vector=236
<idle>-0 [006] d..1 23454.902250: cpu_idle: state=0 cpu_id=6
<idle>-0 [002] .N.1 23454.902250: cpu_idle: state=4294967295 cpu_id=2
<idle>-0 [002] dN.1 23454.902251: rcu_utilization: Start context switch
<idle>-0 [002] dN.1 23454.902252: rcu_utilization: End context switch
<idle>-0 [001] ...1 23454.902252: cpu_idle: state=4294967295 cpu_id=1
<idle>-0 [002] dN.3 23454.902253: prandom_u32: ret=3692516021
<idle>-0 [001] d..1 23454.902254: cpu_idle: state=0 cpu_id=1
<idle>-0 [002] d..2 23454.902254: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=cyclictest next_pid=12275 next_prio=19
<idle>-0 [002] d..4 23454.902256: wakeup_lat: next_comm=cyclictest lat=17
<idle>-0 [002] d..5 23454.902258: <stack trace>
=> trace_event_raw_event_synth
=> action_trace
=> event_hist_trigger
=> event_triggers_call
=> trace_event_buffer_commit
=> trace_event_raw_event_sched_switch
=> __traceiter_sched_switch
=> __schedule
=> schedule_idle
=> do_idle
=> cpu_startup_entry
=> secondary_startup_64_no_verify✨ the options for sqlhist, bestie, explained ✨
-n wakeup_lat— that's the name, babe 💅 we're calling the synthetic eventwakeup_lat.-e— actually run the commands it printed out. go off, execute.-T— do both a trace action and then a snapshot action (it swaps the buffer into the static snapshot buffer). two-step, iconic.-m lat— trigger the actions wheneverlathits a new maximum value. new record = new drama 🔥
🔍 breakdown of the SQL statement 🔍
'SELECT end.next_comm AS comm, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat FROM ' \
'sched_waking AS start JOIN sched_switch AS end ON start.pid = end.next_pid WHERE end.next_prio < 100 && end.next_comm == "cyclictest"'end.next_comm AS comm— grabs thenext_commfield fromsched_switchand drops it into thecommfield of thewakeup_latsynthetic event. cute little rename.(end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat— takes the delta between thesched_switchtimestamp and thesched_wakingtimestamp. heads up: timestamps are usually recorded in nanoseconds, soTIMESTAMPalone would hand you the full nanosecond value — but hereTIMESTAMP_USECStruncates it down to microseconds. that number gets saved in the variablelat, which also ends up recorded in the synthetic event. so efficient.FROM sched_waking AS start JOIN sched_switch AS end ON start.pid = end.next_pid— this is where the synthetic event gets born ✨ it joinssched_wakingtosched_switch, matching thesched_wakingpidfield with thesched_switchnext_pidfield. also it makesstartan alias forsched_wakingandendan alias forsched_switch, so you can just usestartandendas stand-ins forsched_wakingandsched_switchrespectively for the rest of the SQL statement. nicknames, periodt.WHERE end.next_prio < 100 && end.next_comm == "cyclictest"— filters the logic so it only executes if thesched_wakingnext_priofield is less than100. (important: in the kernel, priorities are inverted — real-time priorities run from0-100where0is the highest priority. so yeah, small number = big power 👑) it also only traces when thenext_comm(the task scheduling in) of thesched_switchevent is named"cyclictest".
🌸 for the trace-cmd(3) command 🌸
trace-cmd start -e all -e wakeup_lat -R stacktracetrace-cmd start— enables tracing (and nope, it does not record to a file).-e all— enable all the events. all of them. no crumbs.-e wakeup_lat -R stacktrace— has the"wakeup_lat"event (our synthetic one, hi 🫶) enable the stacktrace trigger, so for every single instance of the"wakeup_lat"event, a kernel stack trace gets recorded into the ring buffer.
After calling cyclictest (a real-time tool for measuring wakeup latency), go read the snapshot buffer 💖
trace-cmd show -s—trace-cmd showreads the kernel ring buffer, and the-soption reads the snapshot buffer instead of the normal one.
<idle>-0 [002] d..4 23454.902256: wakeup_lat: next_comm=cyclictest lat=17and there it is 😭 we can see the "wakeup_lat" event happened on CPU 2, with a wake up latency of 17 microseconds. slay.
This can be extracted into a trace.dat file that trace-cmd(3) can read and do further analysis on — and kernelshark too, bestie 🦋
# trace-cmd extract -s
# trace-cmd report --cpu 2 | tail -30
<idle>-0 [002] 23454.902238: prandom_u32: ret=1633425088
<idle>-0 [002] 23454.902239: sched_wakeup: cyclictest:12275 [19] CPU:002
<idle>-0 [002] 23454.902241: hrtimer_expire_exit: hrtimer=0xffffbbd68286fe60
<idle>-0 [002] 23454.902241: hrtimer_cancel: hrtimer=0xffffbbd6826efe70
<idle>-0 [002] 23454.902242: hrtimer_expire_entry: hrtimer=0xffffbbd6826efe70 now=23455294430750 function=hrtimer_wakeup/0x0
<idle>-0 [002] 23454.902243: sched_waking: comm=cyclictest pid=12272 prio=120 target_cpu=002
<idle>-0 [002] 23454.902244: prandom_u32: ret=1102749734
<idle>-0 [002] 23454.902246: sched_wakeup: cyclictest:12272 [120] CPU:002
<idle>-0 [002] 23454.902247: hrtimer_expire_exit: hrtimer=0xffffbbd6826efe70
<idle>-0 [002] 23454.902248: write_msr: 6e0, value 4866ce957272
<idle>-0 [002] 23454.902249: local_timer_exit: vector=236
<idle>-0 [002] 23454.902250: cpu_idle: state=4294967295 cpu_id=2
<idle>-0 [002] 23454.902251: rcu_utilization: Start context switch
<idle>-0 [002] 23454.902252: rcu_utilization: End context switch
<idle>-0 [002] 23454.902253: prandom_u32: ret=3692516021
<idle>-0 [002] 23454.902254: sched_switch: swapper/2:0 [120] R ==> cyclictest:12275 [19]
<idle>-0 [002] 23454.902256: wakeup_lat: next_comm=cyclictest lat=17
<idle>-0 [002] 23454.902258: kernel_stack: <stack trace >
=> trace_event_raw_event_synth (ffffffff8121a0db)
=> action_trace (ffffffff8121e9fb)
=> event_hist_trigger (ffffffff8121ca8d)
=> event_triggers_call (ffffffff81216c72)
=> trace_event_buffer_commit (ffffffff811f7618)
=> trace_event_raw_event_sched_switch (ffffffff8110fda4)
=> __traceiter_sched_switch (ffffffff8110d449)
=> __schedule (ffffffff81c02002)
=> schedule_idle (ffffffff81c02c86)
=> do_idle (ffffffff8111e898)
=> cpu_startup_entry (ffffffff8111eba9)
=> secondary_startup_64_no_verify (ffffffff81000107)🐛 BUGS 🐛
okay so real talk 💀 since sqlhist is literally just example code from a man page, it is guaranteed to contain lots of bugs. like, a lot. for one thing, not all the error paths are covered properly. you've been warned, bestie 🙈
👀 SEE ALSO 👀
✍️ AUTHOR ✍️
Written by Steven Rostedt, <rostedt@goodmis.org[1]> 🫶
🔗 RESOURCES 🔗
https://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git/
📜 COPYING 📜
Copyright (C) 2021 , Inc. Free use of this software is granted under the terms of the GNU Public License (GPL). 💜
📝 NOTES 📝
rostedt@goodmis.orgmailto:rostedt@goodmis.org
and that's the whole vibe check, bestie — this was libtracefs 1.8.4, dated 10/21/2026, page SQLHIST(1). go forth and trace ✨🎀💅
📦 where this page comes from
- arch rolling: libtracefs 1.8.4-1 · GPL-2.0-only AND LGPL-2.1-only
- 💖 girlified by deepseek-ai/DeepSeek-V4.1-Flash-1017 on : a language model's rewrite of the original, under its terms