Commit | Line | Data |
---|---|---|
5ba3f43e A |
1 | #!/usr/local/bin/luatrace -s |
2 | ||
3 | trace_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 | |
10 | end | |
11 | ||
12 | initial_timestamp = 0 | |
13 | ||
14 | function 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 | |
38 | end | |
39 | ||
40 | function 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 | |
60 | end | |
61 | ||
62 | function 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 | |
75 | end | |
76 | ||
77 | kqrequest_state_strings = { | |
cb323159 | 78 | ['WAKEUP'] = 1, |
5ba3f43e A |
79 | } |
80 | ||
81 | kqueue_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, | |
cb323159 A |
94 | ['R2K'] = 0x1000, |
95 | ['TURNSTILE'] = 0x2000, | |
5ba3f43e A |
96 | } |
97 | ||
98 | knote_state_strings = { | |
99 | ['ACTIVE'] = 0x0001, | |
100 | ['QUEUED'] = 0x0002, | |
101 | ['DISABLED'] = 0x0004, | |
102 | ['DROPPING'] = 0x0008, | |
d9a64523 | 103 | ['LOCKED'] = 0x0010, |
cb323159 | 104 | ['POSTING'] = 0x0020, |
5ba3f43e A |
105 | ['STAYACTIVE'] = 0x0040, |
106 | ['DEFERDELETE'] = 0x0080, | |
cb323159 A |
107 | ['MERGE_QOS'] = 0x0100, |
108 | ['REQVANISH'] = 0x0200, | |
109 | ['VANISHED'] = 0x0400, | |
5ba3f43e | 110 | ['SUPPRESSED'] = 0x0800, |
5ba3f43e | 111 | } |
5ba3f43e A |
112 | |
113 | kevent_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 | ||
130 | function 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' | |
cb323159 A |
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 | ||
5ba3f43e | 165 | elseif filt == 17 then |
cb323159 | 166 | return 'KQREAD' |
5ba3f43e | 167 | elseif filt == 18 then |
cb323159 | 168 | return 'PIPE_N' |
5ba3f43e | 169 | elseif filt == 19 then |
cb323159 | 170 | return 'PIPE_R' |
5ba3f43e | 171 | elseif filt == 20 then |
cb323159 | 172 | return 'PIPE_W' |
5ba3f43e | 173 | elseif filt == 21 then |
cb323159 | 174 | return 'PTSD' |
5ba3f43e | 175 | elseif filt == 22 then |
cb323159 | 176 | return 'SOREAD' |
5ba3f43e | 177 | elseif filt == 23 then |
cb323159 | 178 | return 'SOWRITE' |
5ba3f43e | 179 | elseif filt == 24 then |
cb323159 | 180 | return 'SCK' |
5ba3f43e | 181 | elseif filt == 25 then |
cb323159 | 182 | return 'SOEXCEPT' |
5ba3f43e | 183 | elseif filt == 26 then |
cb323159 | 184 | return 'SPEC' |
5ba3f43e | 185 | elseif filt == 27 then |
cb323159 | 186 | return 'BPFREAD' |
5ba3f43e | 187 | elseif filt == 28 then |
cb323159 | 188 | return 'NECP_FD' |
5ba3f43e | 189 | elseif filt == 29 then |
cb323159 A |
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 | |
5ba3f43e | 200 | return 'TTY' |
cb323159 A |
201 | elseif filt == 35 then |
202 | return 'PTMX' | |
203 | elseif filt == 36 then | |
204 | return 'DETACHED' | |
5ba3f43e A |
205 | else |
206 | return string.format('[%d]', filt) | |
207 | end | |
208 | end | |
209 | ||
210 | -- kqueue lifecycle | |
211 | ||
212 | function 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 | |
228 | end | |
229 | ||
230 | trace_eventname("KEVENT_kq_processing_begin", processing_begin(false)) | |
231 | trace_eventname("KEVENT_kqwq_processing_begin", processing_begin(true)) | |
232 | trace_eventname("KEVENT_kqwl_processing_begin", processing_begin(false)) | |
233 | ||
234 | function 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 | |
244 | end | |
245 | ||
246 | trace_eventname("KEVENT_kq_processing_end", processing_end(false)) | |
247 | trace_eventname("KEVENT_kqwq_processing_end", processing_end(true)) | |
248 | trace_eventname("KEVENT_kqwl_processing_end", processing_end(false)) | |
249 | ||
250 | trace_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)) | |
254 | end) | |
255 | ||
256 | trace_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)) | |
259 | end) | |
260 | ||
261 | trace_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), | |
d9a64523 | 271 | duplicate and ", duplicate" or "") |
5ba3f43e A |
272 | end) |
273 | ||
274 | trace_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) | |
280 | end) | |
281 | ||
282 | function 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 | |
288 | end | |
289 | ||
290 | function 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)) | |
305 | end | |
306 | ||
307 | trace_eventname("KEVENT_kqwq_thread_request", thread_request(true)) | |
308 | trace_eventname("KEVENT_kqwl_thread_request", thread_request(false)) | |
309 | trace_eventname("KEVENT_kqwl_thread_adjust", thread_adjust) | |
310 | ||
311 | function 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 | |
318 | end | |
319 | ||
320 | trace_eventname("KEVENT_kq_register", kevent_register(false)) | |
321 | trace_eventname("KEVENT_kqwq_register", kevent_register(true)) | |
322 | trace_eventname("KEVENT_kqwl_register", kevent_register(false)) | |
323 | ||
324 | function 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 | |
331 | end | |
332 | ||
333 | trace_eventname("KEVENT_kq_process", kevent_process(false)) | |
334 | trace_eventname("KEVENT_kqwq_process", kevent_process(true)) | |
335 | trace_eventname("KEVENT_kqwl_process", kevent_process(false)) |