tools/trace/bridgetime.lua

   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 get_prefix = function(buf, char)
  14         -- if initial_timestamp == 0 then
  15                 -- initial_timestamp = buf.timestamp
  16         -- end
  17         local secs = trace.convert_timestamp_to_nanoseconds(buf.timestamp - initial_timestamp) / 1000000000
  18
  19         return string.format("%s %6.9f %-30s",
  20                 char, secs, buf.debugname)
  21 end
  22
  23 initial_arm_timestamp = 0
  24 format_timestamp_arm = function(ts)
  25         local secs = trace.convert_timestamp_to_nanoseconds(ts - initial_arm_timestamp) / 1000000000
  26         return string.format("%6.9f", secs);
  27 end
  28
  29 initial_intel_timestamp = 0
  30 format_timestamp_intel = function(ts)
  31         local secs = (ts - initial_intel_timestamp) / 1000000000
  32         return string.format("%6.9f", secs);
  33 end
  34
  35 format_timestamp_ns = function(ts)
  36         local secs = (ts) / 1000000000
  37         return string.format("%6.9f", secs);
  38 end
  39
  40 trace_codename("MACH_CLOCK_BRIDGE_RESET_TS", function(buf)
  41         local prefix = get_prefix(buf, "X")
  42         local reason = "UNKNOWN";
  43         if buf[3] == 1 then
  44                 reason = "RecvSentinel"
  45         elseif buf[3] == 2 then
  46                 reason = "ResetTrue"
  47         elseif buf[3] == 3 then
  48                 reason = "RateZero"
  49         elseif buf[3] == 4 then
  50                 reason = "TSMismatch"
  51         end
  52         printf("%s %-15s ( %-10s %-10s ) ----------------------------------------\n",
  53                 prefix, reason, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]))
  54
  55         -- initial_arm_timestamp = buf[1]
  56         -- initial_intel_timestamp = buf[2]
  57 end)
  58
  59 trace_codename("MACH_CLOCK_BRIDGE_TS_PARAMS", function(buf)
  60         local prefix = get_prefix(buf, ">")
  61
  62         local rate
  63         if darwin.uint64_to_double then
  64                 rate = darwin.uint64_to_double(buf[3])
  65         else
  66                 rate = math.nan
  67         end
  68
  69         printf("%s %30s( %-10s %-10s ) rate = %f\n",
  70                 prefix, "", format_timestamp_ns(buf[1]), format_timestamp_intel(buf[2]),
  71                 rate)
  72 end)
  73
  74 trace_codename("MACH_CLOCK_BRIDGE_REMOTE_TIME", function(buf)
  75         local prefix = get_prefix(buf, "-")
  76
  77         printf("%s ( %-10s %-10s ) @ %-20s\n",
  78                 prefix, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]), format_timestamp_arm(buf[3]))
  79 end)
  80
  81 trace_codename("MACH_CLOCK_BRIDGE_RCV_TS", function(buf)
  82         local prefix = get_prefix(buf, "<")
  83
  84         if buf[2] == 0xfffffffffffffffe then
  85                 printf("%s ( %-10s  Sleep )\n",
  86                         prefix, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]))
  87         elseif buf[2] == 0xfffffffffffffffd then
  88                 printf("%s ( %-10s Wake )\n",
  89                         prefix, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]))
  90         elseif buf[2] == 0xfffffffffffffffc then
  91                 printf("%s ( %-10s Reset )\n",
  92                         prefix, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]))
  93         else
  94                 local skip = ""
  95                 if buf[1] == 0 then
  96                         skip = "Int handler"
  97                 end
  98                 printf("%s ( %-10s %-10s ) %s\n",
  99                         prefix, format_timestamp_arm(buf[1]), format_timestamp_intel(buf[2]), skip)
 100         end
 101
 102 end)
 103
 104 trace_codename("MACH_CLOCK_BRIDGE_SKIP_TS", function(buf)
 105         local prefix = get_prefix(buf, "*")
 106
 107         if buf[4] > 0 then
 108                 printf("%s SKIP_RESET:%3d (Cur: %-10s Prev:%-10s) %-10s\n",
 109                         prefix, buf[4], format_timestamp_arm(buf[1]), format_timestamp_arm(buf[3]),
 110                         format_timestamp_intel(buf[2]))
 111         else
 112                 printf("%s SKIP_DISTANCE: (Cur: %-10s Prev: %-10s) %-10s\n",
 113                         prefix, format_timestamp_arm(buf[1]), format_timestamp_arm(buf[3]),
 114                         format_timestamp_intel(buf[2]))
 115         end
 116
 117 end)
 118
 119 trace_codename("MACH_CLOCK_BRIDGE_TS_MISMATCH", function(buf)
 120         local prefix = get_prefix(buf, "?")
 121
 122         local diff = (math.abs(buf[2] - buf[3]))/1000000
 123
 124         printf("%s ( Cur: %-10s Pred: %-10s Diff: %5.6f ms Count: %d ) @ %-20s\n",
 125                 prefix, format_timestamp_intel(buf[2]), format_timestamp_intel(buf[3]),
 126                 diff, buf[4], format_timestamp_arm(buf[1]))
 127
 128 end)
 129
 130 trace_codename("MACH_CLOCK_BRIDGE_OBSV_RATE", function(buf)
 131         local prefix = get_prefix(buf, "=")
 132
 133         local rate
 134         if darwin.uint64_to_double then
 135                 rate = darwin.uint64_to_double(buf[1])
 136         else
 137                 rate = math.nan
 138         end
 139
 140         printf("%s obsv_rate = %f exceeded limits(0.8, 1.2)\n", prefix, rate)
 141
 142 end)