1#!/usr/local/bin/luatrace -s 2 3trace_eventname = function(codename, callback) 4 local debugid = trace.debugid(codename) 5 if debugid ~= 0 then 6 trace.single(debugid,callback) 7 else 8 printf("WARNING: Cannot locate debugid for '%s'\n", codename) 9 end 10end 11 12initial_timestamp = 0 13 14function event_prefix_string(buf, workq) 15 if initial_timestamp == 0 then 16 initial_timestamp = buf.timestamp 17 end 18 local secs = trace.convert_timestamp_to_nanoseconds(buf.timestamp - initial_timestamp) / 1000000000 19 20 local type 21 if trace.debugid_is_start(buf.debugid) then 22 type = "→" 23 elseif trace.debugid_is_end(buf.debugid) then 24 type = "←" 25 else 26 type = "↔" 27 end 28 29 proc = buf.command 30 31 local prefix = string.format("%s %6.9f %-17s [%05d.%06x] %-28s\t", 32 type, secs, proc, buf.pid, buf.threadid, buf.debugname) 33 if not workq then 34 prefix = prefix .. string.format(" 0x%16x", buf.arg1) 35 end 36 37 return prefix 38end 39 40function qos_string(qos) 41 if qos == 0 then 42 return "--" 43 elseif qos == 1 then 44 return "MT" 45 elseif qos == 2 then 46 return "BG" 47 elseif qos == 3 then 48 return "UT" 49 elseif qos == 4 then 50 return "DF" 51 elseif qos == 5 then 52 return "IN" 53 elseif qos == 6 then 54 return "UI" 55 elseif qos == 7 then 56 return "MG" 57 else 58 return string.format("??[0x%x]", qos) 59 end 60end 61 62function state_string(strings, state) 63 local str = '' 64 local first = true 65 for name, bit in pairs(strings) do 66 if (state & bit) == bit then 67 if not first then 68 str = str .. ' ' 69 end 70 str = str .. name 71 first = false 72 end 73 end 74 return str 75end 76 77kqrequest_state_strings = { 78 ['WAKEUP'] = 1, 79} 80 81kqueue_state_strings = { 82 ['SEL'] = 0x001, 83 ['SLEEP'] = 0x002, 84 ['PROCWAIT'] = 0x004, 85 ['KEV32'] = 0x008, 86 ['KEV64'] = 0x010, 87 ['KEV_QOS'] = 0x020, 88 ['WORKQ'] = 0x040, 89 ['WORKLOOP'] = 0x080, 90 ['PROCESSING'] = 0x100, 91 ['DRAIN'] = 0x200, 92 ['WAKEUP'] = 0x400, 93 ['DYNAMIC'] = 0x800, 94 ['R2K'] = 0x1000, 95 ['TURNSTILE'] = 0x2000, 96} 97 98knote_state_strings = { 99 ['ACTIVE'] = 0x0001, 100 ['QUEUED'] = 0x0002, 101 ['DISABLED'] = 0x0004, 102 ['DROPPING'] = 0x0008, 103 ['LOCKED'] = 0x0010, 104 ['POSTING'] = 0x0020, 105 ['STAYACTIVE'] = 0x0040, 106 ['DEFERDELETE'] = 0x0080, 107 ['MERGE_QOS'] = 0x0100, 108 ['REQVANISH'] = 0x0200, 109 ['VANISHED'] = 0x0400, 110 ['SUPPRESSED'] = 0x0800, 111} 112 113kevent_flags_strings = { 114 ['ADD'] = 0x0001, 115 ['DELETE'] = 0x0002, 116 ['ENABLE'] = 0x0004, 117 ['DISABLE'] = 0x0008, 118 ['ONESHOT'] = 0x0010, 119 ['CLEAR'] = 0x0020, 120 ['RECEIPT'] = 0x0040, 121 ['DISPATCH'] = 0x0080, 122 ['UDATA_SPECIFIC'] = 0x0100, 123 ['VANISHED'] = 0x0200, 124 ['FLAG0'] = 0x1000, 125 ['FLAG1'] = 0x2000, 126 ['EOF'] = 0x8000, 127 ['ERROR'] = 0x4000, 128} 129 130function kevent_filter_string(filt) 131 if filt == -1 then 132 return 'READ' 133 elseif filt == -2 then 134 return 'WRITE' 135 elseif filt == -3 then 136 return 'AIO' 137 elseif filt == -4 then 138 return 'VNODE' 139 elseif filt == -5 then 140 return 'PROC' 141 elseif filt == -6 then 142 return 'SIGNAL' 143 elseif filt == -7 then 144 return 'TIMER' 145 elseif filt == -8 then 146 return 'MACHPORT' 147 elseif filt == -9 then 148 return 'FS' 149 elseif filt == -10 then 150 return 'USER' 151 -- -11 unused 152 elseif filt == -12 then 153 return 'VM' 154 elseif filt == -13 then 155 return 'SOCK' 156 elseif filt == -14 then 157 return 'MEMORYSTATUS' 158 elseif filt == -15 then 159 return 'EXCEPT' 160 elseif filt == -16 then 161 return 'NW_CHANNEL' 162 elseif filt == -17 then 163 return 'WORKLOOP' 164 165 elseif filt == 17 then 166 return 'KQREAD' 167 elseif filt == 18 then 168 return 'PIPE_N' 169 elseif filt == 19 then 170 return 'PIPE_R' 171 elseif filt == 20 then 172 return 'PIPE_W' 173 elseif filt == 21 then 174 return 'PTSD' 175 elseif filt == 22 then 176 return 'SOREAD' 177 elseif filt == 23 then 178 return 'SOWRITE' 179 elseif filt == 24 then 180 return 'SCK' 181 elseif filt == 25 then 182 return 'SOEXCEPT' 183 elseif filt == 26 then 184 return 'SPEC' 185 elseif filt == 27 then 186 return 'BPFREAD' 187 elseif filt == 28 then 188 return 'NECP_FD' 189 elseif filt == 29 then 190 return 'SKYWALK_CHANNEL_W' 191 elseif filt == 30 then 192 return 'SKYWALK_CHANNEL_R' 193 elseif filt == 31 then 194 return 'SKYWALK_CHANNEL_E' 195 elseif filt == 32 then 196 return 'FSEVENT' 197 elseif filt == 33 then 198 return 'VN' 199 elseif filt == 34 then 200 return 'TTY' 201 elseif filt == 35 then 202 return 'PTMX' 203 elseif filt == 36 then 204 return 'DETACHED' 205 else 206 return string.format('[%d]', filt) 207 end 208end 209 210-- kqueue lifecycle 211 212function processing_begin(workq) 213 return function(buf) 214 local prefix = event_prefix_string(buf, workq) 215 if trace.debugid_is_start(buf.debugid) then 216 local qos 217 if workq then 218 qos = buf.arg2 219 else 220 qos = buf.arg3 221 end 222 printf("%s QoS = %s\n", prefix, qos_string(qos)) 223 else 224 printf("%s request thread = 0x%x, kqrequest state = %s\n", prefix, 225 buf.arg1, state_string(kqrequest_state_strings, buf.arg2)) 226 end 227 end 228end 229 230trace_eventname("KEVENT_kq_processing_begin", processing_begin(false)) 231trace_eventname("KEVENT_kqwq_processing_begin", processing_begin(true)) 232trace_eventname("KEVENT_kqwl_processing_begin", processing_begin(false)) 233 234function processing_end(workq) 235 return function(buf) 236 local qos 237 if workq then 238 qos = buf.arg2 239 else 240 qos = buf.arg3 241 end 242 printf("%s QoS = %s\n", event_prefix_string(buf, workq), qos_string(qos)) 243 end 244end 245 246trace_eventname("KEVENT_kq_processing_end", processing_end(false)) 247trace_eventname("KEVENT_kqwq_processing_end", processing_end(true)) 248trace_eventname("KEVENT_kqwl_processing_end", processing_end(false)) 249 250trace_eventname("KEVENT_kqwq_bind", function(buf) 251 printf("%s thread = 0x%x, QoS = %s, kqrequest state = %s\n", 252 event_prefix_string(buf, true), buf.arg1, qos_string(buf.arg3), 253 state_string(kqrequest_state_strings, buf.arg4)) 254end) 255 256trace_eventname("KEVENT_kqwq_unbind", function(buf) 257 printf("%s thread = 0x%x, QoS = %s\n", event_prefix_string(buf, true), 258 buf.arg1, qos_string(buf.arg3)) 259end) 260 261trace_eventname("KEVENT_kqwl_bind", function(buf) 262 qos = buf.arg3 & 0xff 263 duplicate = buf.arg3 & (1 << 8) 264 kqr_override_qos_delta = buf.arg4 >> 8 265 kqr_state = buf.arg4 & 0xff 266 267 printf("%s thread = 0x%x, QoS = %s, override QoS delta = %d, kqrequest state = %s%s\n", 268 event_prefix_string(buf, false), buf.arg2, qos_string(qos), 269 kqr_override_qos_delta, 270 state_string(kqrequest_state_strings, kqr_state), 271 duplicate and ", duplicate" or "") 272end) 273 274trace_eventname("KEVENT_kqwl_unbind", function(buf) 275 flags = buf.arg3 276 qos = buf.arg4 277 278 printf("%s thread = 0x%x, QoS = %s, flags = 0x%x\n", event_prefix_string(buf, false), 279 buf.arg2, qos_string(qos), flags) 280end) 281 282function thread_request(workq) 283 return function(buf) 284 printf("%s QoS = %s, kqrequest state = %s, override QoS delta = %d\n", 285 event_prefix_string(buf, workq), qos_string(buf.arg2), 286 state_string(kqrequest_state_strings, buf.arg3), buf.arg3 >> 8) 287 end 288end 289 290function thread_adjust(buf) 291 tid = buf.arg2 292 kqr_qos = buf.arg3 >> 8 293 new_qos = buf.arg3 & 0xff 294 kqr_qos_override = buf.arg4 >> 8 295 kqr_state = buf.arg4 & 0xff 296 297 printf("%s thread = 0x%x, old/new QoS = %s/%s, old/new override QoS delta = %d/%d, kqrequest state = %s\n", 298 event_prefix_string(buf, false), 299 tid, 300 qos_string(kqr_qos), 301 qos_string(new_qos), 302 kqr_qos_override, 303 new_qos - kqr_qos, 304 state_string(kqrequest_state_strings, kqr_state)) 305end 306 307trace_eventname("KEVENT_kqwq_thread_request", thread_request(true)) 308trace_eventname("KEVENT_kqwl_thread_request", thread_request(false)) 309trace_eventname("KEVENT_kqwl_thread_adjust", thread_adjust) 310 311function kevent_register(workq) 312 return function(buf) 313 printf("%s kevent udata = 0x%x, kevent filter = %s, kevent flags = %s\n", 314 event_prefix_string(buf, workq), buf.arg2, 315 kevent_filter_string(buf.arg4), 316 state_string(kevent_flags_strings, buf.arg3)) 317 end 318end 319 320trace_eventname("KEVENT_kq_register", kevent_register(false)) 321trace_eventname("KEVENT_kqwq_register", kevent_register(true)) 322trace_eventname("KEVENT_kqwl_register", kevent_register(false)) 323 324function kevent_process(workq) 325 return function(buf) 326 printf("%s kevent ident = 0x%x, udata = 0x%x, kevent filter = %s, knote status = %s\n", 327 event_prefix_string(buf, workq), buf.arg3 >> 32, buf.arg2, 328 kevent_filter_string(buf.arg4), 329 state_string(knote_state_strings, buf.arg3 & 0xffffffff)) 330 end 331end 332 333trace_eventname("KEVENT_kq_process", kevent_process(false)) 334trace_eventname("KEVENT_kqwq_process", kevent_process(true)) 335trace_eventname("KEVENT_kqwl_process", kevent_process(false)) 336