Now available: The Design and Implementation of the FreeBSD Operating System (Second Edition)
[ source navigation ] [ diff markup ] [ identifier search ] [ freetext search ] [ file search ] [ list types ] [ track identifier ]
FreeBSD/Linux Kernel Cross Reference
sys/tools/trace/wqtrace.lua
Version:
- FREEBSD - FREEBSD-13-STABLE - FREEBSD-13-0 - FREEBSD-12-STABLE - FREEBSD-12-0 - FREEBSD-11-STABLE - FREEBSD-11-0 - FREEBSD-10-STABLE - FREEBSD-10-0 - FREEBSD-9-STABLE - FREEBSD-9-0 - FREEBSD-8-STABLE - FREEBSD-8-0 - FREEBSD-7-STABLE - FREEBSD-7-0 - FREEBSD-6-STABLE - FREEBSD-6-0 - FREEBSD-5-STABLE - FREEBSD-5-0 - FREEBSD-4-STABLE - FREEBSD-3-STABLE - FREEBSD22 - l41 - OPENBSD - linux-2.6 - MK84 - PLAN9 - xnu-8792
SearchContext: - none - 3 - 10
SearchContext: - none - 3 - 10
1 #!/usr/local/bin/luatrace -s 2 3 trace_codename = 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 pid_map = {}; 14 get_prefix = function(buf) 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 prefix 21 if trace.debugid_is_start(buf.debugid) then 22 prefix = "→" 23 elseif trace.debugid_is_end(buf.debugid) then 24 prefix = "←" 25 else 26 prefix = "↔" 27 end 28 29 local proc 30 if buf.pid == buf[1] then 31 proc = buf.command 32 if pid_map[buf[1]] == nil then 33 pid_map[buf[1]] = buf.command 34 end 35 elseif pid_map[buf[1]] ~= nil then 36 proc = pid_map[buf[1]] 37 else 38 proc = "UNKNOWN" 39 end 40 41 return string.format("%s %6.9f %-17s [%05d.%06x] %-24s", 42 prefix, secs, proc, buf.pid, buf.threadid, buf.debugname) 43 end 44 45 parse_pthread_priority = function(pri) 46 pri = pri & 0xffffffff 47 if (pri & 0x02000000) == 0x02000000 then 48 return "Manager" 49 end 50 local qos = (pri & 0x00ffff00) >> 8 51 if qos == 0x20 then 52 return string.format("UI[%x]", pri); 53 elseif qos == 0x10 then 54 return string.format("IN[%x]", pri); 55 elseif qos == 0x08 then 56 return string.format("DF[%x]", pri); 57 elseif qos == 0x04 then 58 return string.format("UT[%x]", pri); 59 elseif qos == 0x02 then 60 return string.format("BG[%x]", pri); 61 elseif qos == 0x01 then 62 return string.format("MT[%x]", pri); 63 elseif qos == 0x00 then 64 return string.format("--[%x]", pri); 65 else 66 return string.format("??[%x]", pri); 67 end 68 end 69 70 parse_thread_qos = function(pri) 71 if pri == 7 then 72 return string.format("MG", pri); 73 elseif pri == 6 then 74 return string.format("UI", pri); 75 elseif pri == 5 then 76 return string.format("IN", pri); 77 elseif pri == 4 then 78 return string.format("DF", pri); 79 elseif pri == 3 then 80 return string.format("UT", pri); 81 elseif pri == 2 then 82 return string.format("BG", pri); 83 elseif pri == 1 then 84 return string.format("MT", pri); 85 elseif pri == 0 then 86 return string.format("--", pri); 87 else 88 return string.format("??[%x]", pri); 89 end 90 end 91 92 parse_thactive_req_qos = function(pri) 93 if pri ~= 0 then 94 return parse_thread_qos(pri) 95 end 96 return "None" 97 end 98 99 get_thactive = function(low, high) 100 return string.format("req: %s, MG: %d, UI: %d, IN: %d, DE: %d, UT: %d, BG: %d, MT: %d", 101 parse_thactive_req_qos(high >> (16 * 3)), (high >> (2 * 16)) & 0xffff, 102 (high >> (1 * 16)) & 0xffff, (high >> (0 * 16)) & 0xffff, 103 (low >> (3 * 16)) & 0xffff, (low >> (2 * 16)) & 0xffff, 104 (low >> (1 * 16)) & 0xffff, (low >> (0 * 16)) & 0xffff) 105 end 106 107 -- workqueue lifecycle 108 109 trace_codename("wq_pthread_exit", function(buf) 110 local prefix = get_prefix(buf) 111 if trace.debugid_is_start(buf.debugid) then 112 printf("%s\tprocess is exiting\n",prefix) 113 else 114 printf("%s\tworkqueue marked as exiting and timer is complete\n",prefix) 115 end 116 end) 117 118 trace_codename("wq_workqueue_exit", function(buf) 119 local prefix = get_prefix(buf) 120 if trace.debugid_is_start(buf.debugid) then 121 printf("%s\tall threads have exited, cleaning up\n",prefix) 122 else 123 printf("%s\tclean up complete\n",prefix) 124 end 125 end) 126 127 trace_codename("wq_start_add_timer", function(buf) 128 local prefix = get_prefix(buf) 129 printf("%s\tarming timer to fire in %d us (flags: %x, reqcount: %d)\n", 130 prefix, buf.arg4, buf.arg3, buf.arg2) 131 end) 132 133 trace_codename("wq_add_timer", function(buf) 134 local prefix = get_prefix(buf) 135 if trace.debugid_is_start(buf.debugid) then 136 printf("%s\tadd_timer fired (flags: %x, nthreads: %d, thidlecount: %d)\n", 137 prefix, buf.arg2, buf.arg3, buf.arg4) 138 elseif trace.debugid_is_end(buf.debugid) then 139 printf("%s\tadd_timer completed (start_timer: %x, nthreads: %d, thidlecount: %d)\n", 140 prefix, buf.arg2, buf.arg3, buf.arg4) 141 end 142 end) 143 144 trace_codename("wq_select_threadreq", function(buf) 145 local prefix = get_prefix(buf) 146 if buf[2] == 0 then 147 printf("%s\tSelection failed: process exiting\n", prefix) 148 elseif buf[2] == 1 then 149 printf("%s\tSelection failed: no request\n", prefix) 150 elseif buf[2] == 2 then 151 printf("%s\tSelection failed: throttled\n", prefix) 152 elseif buf[2] == 3 then 153 printf("%s\tSelection failed: scheduler would preempt\n", prefix) 154 end 155 end) 156 157 trace_codename("wq_creator_select", function(buf) 158 local prefix = get_prefix(buf) 159 if buf[2] == 1 then 160 printf("%s\t\tcreator %x overridden at %s\n", prefix, buf[3], 161 parse_thread_qos(buf[4])) 162 elseif buf[2] == 2 then 163 printf("%s\t\tcreator %x selected at %s\n", prefix, buf[3], 164 parse_thread_qos(buf[4])) 165 elseif buf[2] == 3 then 166 printf("%s\t\tcreator idled (%d yields)\n", prefix, buf[4]) 167 elseif buf[2] == 4 then 168 printf("%s\t\tcreator removed (%d yields)\n", prefix, buf[4]) 169 end 170 end) 171 172 trace_codename("wq_creator_yield", function(buf) 173 local prefix = get_prefix(buf) 174 local reason = "unknown" 175 if buf[2] == 1 then 176 reason = "fast steal rate" 177 elseif buf[2] == 2 then 178 reason = "above ncpu scheduled" 179 end 180 printf("%s\t\tcreator yielded (%s, current:%d snapshot:%d)\n", 181 prefix, reason, buf[3], buf[4]) 182 end) 183 184 trace_codename("wq_thread_logical_run", function(buf) 185 local prefix = get_prefix(buf) 186 if trace.debugid_is_start(buf.debugid) then 187 printf("%s\tthread unparking (request %x)\n", prefix, buf[2]) 188 else 189 printf("%s\tthread parking\n", prefix) 190 end 191 end) 192 193 trace.enable_thread_cputime() 194 runthread_time_map = {} 195 runthread_cputime_map = {} 196 trace_codename("wq_runthread", function(buf) 197 local prefix = get_prefix(buf) 198 if trace.debugid_is_start(buf.debugid) then 199 printf("%s\tSTART running thread\n", prefix) 200 runthread_time_map[buf.threadid] = buf.timestamp; 201 runthread_cputime_map[buf.threadid] = trace.cputime_for_thread(buf.threadid); 202 elseif runthread_time_map[buf.threadid] then 203 local time = buf.timestamp - runthread_time_map[buf.threadid] 204 local cputime = trace.cputime_for_thread(buf.threadid) - runthread_cputime_map[buf.threadid] 205 206 local time_ms = trace.convert_timestamp_to_nanoseconds(time) / 1000000 207 local cputime_ms = trace.convert_timestamp_to_nanoseconds(cputime) / 1000000 208 209 printf("%s\tDONE running thread: time = %6.6f ms, cputime = %6.6f ms\n", 210 prefix, time_ms, cputime_ms) 211 212 runthread_time_map[buf.threadid] = 0 213 runthread_cputime_map[buf.threadid] = 0 214 elseif trace.debugid_is_end(buf.debugid) then 215 printf("%s\tDONE running thread\n", prefix) 216 end 217 end) 218 219 trace_codename("wq_thactive_update", function(buf) 220 local prefix = get_prefix(buf) 221 local thactive = get_thactive(buf[2], buf[3]) 222 printf("%s\tthactive updated (%s)\n", prefix, thactive) 223 end) 224 225 trace_codename("wq_thread_block", function(buf) 226 local prefix = get_prefix(buf) 227 local req_pri = parse_thread_qos(buf[3] >> 8) 228 if trace.debugid_is_start(buf.debugid) then 229 printf("%s\tthread blocked (activecount: %d, priority: %s, req_pri: %s, reqcount: %d, start_timer: %d)\n", 230 prefix, buf[2], parse_thread_qos(buf[3] & 0xff), req_pri, buf[4] >> 1, buf[4] & 0x1) 231 else 232 printf("%s\tthread unblocked (activecount: %d, priority: %s, req_pri: %s, threads_scheduled: %d)\n", 233 prefix, buf[2], parse_thread_qos(buf[3] & 0xff), req_pri, buf[4]) 234 end 235 end) 236 237 trace_codename("wq_thread_create_failed", function(buf) 238 local prefix = get_prefix(buf) 239 if buf[3] == 0 then 240 printf("%s\tfailed to create new workqueue thread, kern_return: 0x%x\n", 241 prefix, buf[2]) 242 elseif buf[3] == 1 then 243 printf("%s\tfailed to vm_map workq thread stack: 0x%x\n", prefix, buf[2]) 244 elseif buf[3] == 2 then 245 printf("%s\tfailed to vm_protect workq thread guardsize: 0x%x\n", prefix, buf[2]) 246 end 247 end) 248 249 trace_codename("wq_thread_create", function(buf) 250 printf("%s\tcreated new workqueue thread\n", get_prefix(buf)) 251 end) 252 253 trace_codename("wq_thread_terminate", function(buf) 254 local prefix = get_prefix(buf) 255 local what 256 if trace.debugid_is_start(buf.debugid) then 257 what = "try to terminate thread" 258 else 259 what = "terminated thread" 260 end 261 printf("%s\t%s: currently idle %d\n", prefix, what, buf[2]) 262 end) 263 264 trace_codename("wq_wqops_reqthreads", function(buf) 265 local prefix = get_prefix(buf) 266 printf("%s\tlegacy thread request made for %d threads at %s\n", prefix, buf[2], parse_pthread_priority(buf[3])); 267 end) 268 269 trace_codename("wq_thread_request_initiate", function(buf) 270 local prefix = get_prefix(buf) 271 printf("%s\tthread request %x made at %s (count:%d)\n", prefix, buf[2], parse_thread_qos(buf[3]), buf[4]); 272 end) 273 274 trace_codename("wq_thread_request_modify", function(buf) 275 local prefix = get_prefix(buf) 276 printf("%s\tthread request %x priorty updated to %s\n", prefix, buf[2], parse_thread_qos(buf[3])); 277 end) 278 279 trace_codename("wq_thread_request_cancel", function(buf) 280 local prefix = get_prefix(buf) 281 printf("%s\tthread request %x canceled\n", prefix, buf[2], parse_thread_qos(buf[3])); 282 end) 283 284 trace_codename("wq_constrained_admission", function(buf) 285 local prefix = get_prefix(buf) 286 if buf[2] == 1 then 287 printf("fail: %s\twq_constrained_threads_scheduled=%d >= wq_max_constrained_threads=%d\n", 288 prefix, buf[3], buf[4]) 289 elseif (buf[2] == 2) or (buf[2] == 3) then 290 local success = nil; 291 if buf[2] == 2 then success = "success" 292 else success = "fail" end 293 printf("%s\t%s\tthactive_count=%d + busycount=%d >= wq->wq_max_concurrency\n", 294 prefix, success, buf[3], buf[4]) 295 end 296 end) 297 298 trace_codename("wq_cooperative_admission", function(buf) 299 local prefix = get_prefix(buf) 300 if (buf[4] == 1) then 301 printf("%s\tsuccess at qos %s\t wq_cooperative_threads_scheduled=%d >= wq_max_cooperative_threads\n", 302 prefix, parse_thread_qos(buf[2]), buf[1]) 303 elseif (buf[4] == 2) then 304 printf("%s\tsuccess at qos %s\t due to empty bucket, wq_cooperative_threads_scheduled=%d\n", 305 prefix, parse_thread_qos(buf[2]), buf[1]) 306 elseif (buf[4] == 3) then 307 success = "success" 308 if (buf[3] == 0) then 309 success = "fail" 310 end 311 printf("%s\t%s at qos %s\twq_cooperative_threads_scheduled_up_to_qos=%d\n", 312 prefix, success, parse_thread_qos(buf[2]), buf[1]) 313 end 314 end) 315 316 trace_codename("wq_death_call", function(buf) 317 local prefix = get_prefix(buf) 318 if trace.debugid_is_start(buf.debugid) then 319 printf("%s\tentering death call\n", prefix); 320 elseif trace.debugid_is_end(buf.debugid) then 321 printf("%s\tleaving death call\n", prefix); 322 else 323 printf("%s\tscheduling death call\n", prefix); 324 end 325 end) 326 -- 327 -- vim:ts=4:sw=4:noet:
Cache object: 5c8b551994a68324c48b40c331ded9c0
[ source navigation ] [ diff markup ] [ identifier search ] [ freetext search ] [ file search ] [ list types ] [ track identifier ]