Skip to content

Instantly share code, notes, and snippets.

@brianmichel
Created September 26, 2022 13:56
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save brianmichel/9b6b91d93e32a60459f545be996582fc to your computer and use it in GitHub Desktop.
Save brianmichel/9b6b91d93e32a60459f545be996582fc to your computer and use it in GitHub Desktop.
An updated version of the timerfires command that works on macOS 12+
#!/bin/sh
# timerfires
FORMAT='"%8d %5d %-16s %-16s "'
CURRENTTIME='(walltimestamp - starttime) / 1000000'
specifiers=0
opt_pid=0; pid=0
opt_name=0; pname=""
opt_timeout=0; timeout=0
opt_stack=0
opt_verbose=0
opt_aggregate=0
function print_usage() {
cat <<-END >&2
usage:
`basename $0` [-t <timeout>] [-p <pid> | -n <name>] [-s]
-t <timeout> length of time to run in seconds
-p <pid> filter to process with pid
-n <name> filter to process with name
-s show stacks for non-callout timers
-v show verbose output where applicable
-g aggregate output
END
exit 1
}
while getopts ap:n:st:vgh name
do
case $name in
a) specifiers=`expr $specifiers + 1` ;;
p) opt_pid=1; pid=$OPTARG; specifiers=`expr $specifiers + 1` ;;
n) opt_name=1; pname=$OPTARG; specifiers=`expr $specifiers + 1` ;;
s) opt_stack=1 ;;
t) opt_timeout=1; timeout=$OPTARG ;;
v) opt_verbose=1 ;;
g) opt_aggregate=1 ;;
h|?) print_usage ;;
esac
done
if [ $opt_stack -eq 1 ]
then
STACK='stack();'
USTACK='ustack();'
else
STACK='printf("\n");'
USTACK='printf("\n");'
fi
if [ $specifiers -ne 1 ]
then
print_usage
fi
if [[ $opt_name -eq 1 && ${#pname} -gt 15 ]]
then
pname=$(echo "$pname" | cut -c1-15)
echo "Warning: Truncating process name to 15 characters: $pname"
fi
dtrace='
BEGIN
{
starttime = walltimestamp;
printf("%8s %5s %-16s %-16s %s\n", "TIME(ms)", "PID", "PROCESS", "TYPE", "TIMER ROUTINE");
}
dispatch*:::timer-fire
/
(!'$opt_name' || execname == "'$pname'") &&
(!'$opt_pid' || pid == '$pid')
/
{
printf('$FORMAT', '$CURRENTTIME', pid, execname, "dispatch");
usym(arg1);
printf("\n");
}
CFRunLoop*:::timer_fired
/
(!'$opt_name' || execname == "'$pname'") &&
(!'$opt_pid' || pid == '$pid')
/
{
printf('$FORMAT', '$CURRENTTIME', pid, execname, "CF");
'$opt_verbose' ? printf("(%s %s) ", copyinstr(arg2), copyinstr(arg3)) : 1;
usym(arg4);
printf("\n");
}
/* IOTES */
sdt:::iotescallout-expire
/
(!'$opt_name' || "kernel_task" == "'$pname'") &&
(!'$opt_pid' || 0 == '$pid')
/
{
self->accounted_for = 1;
printf('$FORMAT', '$CURRENTTIME', 0, "kernel_task", "IOTES");
sym(arg0);
printf("\n");
}
sdt:::thread_callout-start
/ arg4 /
{
self->accounted_for = 0;
}
/* threadcall */
sdt:::thread_callout-end
/
(!'$opt_name' || "kernel_task" == "'$pname'") &&
(!'$opt_pid' || 0 == '$pid') &&
!self->accounted_for &&
arg4
/
{
printf('$FORMAT', '$CURRENTTIME', 0, "kernel_task", "threadcall");
sym(arg0);
printf("\n");
}
'
# Old probes that I'm not sure work, removed them for the time being, will
# Add them back as we can to see what still works.
# /* kernel_task TTE with continuation */
# sdt:::callout-start
# /
# (!'$opt_name' || "kernel_task" == "'$pname'") &&
# (!'$opt_pid' || 0 == '$pid') &&
# arg0 == (uint64_t)&mach_kernel`thread_timer_expire &&
# ((thread_t)arg1)->task == `kernel_task &&
# !((thread_t)arg1)->kernel_stack
# /
# {
# thread = (thread_t)arg1;
# task = ((thread_t)arg1)->task;
# proc = (proc_t)task->bsd_info;
# procname = proc ? proc->p_comm : "???";
# procpid = proc ? proc->p_pid : 0;
# printf('$FORMAT', '$CURRENTTIME', procpid, procname, "contsleep");
# sym((uint64_t)thread->continuation);
# printf("\n");
# }
# /* other timer call */
# sdt:::callout-start
# /
# (!'$opt_name' || "kernel_task" == "'$pname'") &&
# (!'$opt_pid' || 0 == '$pid') &&
# arg0 != (uint64_t)&mach_kernel`thread_timer_expire &&
# arg0 != (uint64_t)&mach_kernel`thread_call_delayed_timer &&
# arg0 != (uint64_t)&mach_kernel`thread_quantum_expire
# /
# {
# printf('$FORMAT', '$CURRENTTIME', 0, "kernel_task", "timercall");
# sym(arg0);
# printf("\n");
# }
# fbt::thread_unblock:entry
# / ((thread_t)arg0)->task != `kernel_task /
# {
# self->accounted_for = 1;
# }
if [ $opt_timeout -eq 1 ]
then
dtrace=$dtrace'
tick-'$timeout's
{
exit(0);
}
'
fi
if [ $opt_aggregate -eq 1 ]
then
aggregator='
use strict;
my $got_sigint = 0;
sub sigint {
if ($got_sigint) {
exit(1)
}
$got_sigint = 1;
}
$SIG{INT} = \&sigint;
my $aggregation = {};
my $collectstack = 0;
my $stack = "";
my ($time, $pid, $procname, $type, $symbol);
while (<>) {
chomp;
if (/^TIME/) {
next;
} elsif (/^ +([0-9]+) +([0-9]+) ([^ ]+(?: [^ ]+)*) +(sleep|dispatch|CF|threadcall|IOTES|timercall) (.*)$/) {
if ($collectstack == 1) {
$aggregation->{$pid}->{$procname}->{$type}->{$symbol}->{$stack}++;
$stack = "";
$collectstack = 0;
}
($time, $pid, $procname, $type, $symbol) = ($1, $2, $3, $4, $5);
if ($type eq "sleep") {
$collectstack = 1;
} else {
$aggregation->{$pid}->{$procname}->{$type}->{$symbol}->{""}++;
}
} else {
if ($collectstack) {
$stack .= $_ . "\n";
}
}
}
my $i;
my ($tuplesref, $valuesref) = tuples_and_values_of_nested_hash($aggregation);
for ($i = 0; $i < scalar @$tuplesref; $i++) {
my ($pid, $procname, $type, $symbol, $stack) = @{ ${$tuplesref}[$i] };
my $value = ${$valuesref}[$i];
printf("%8d %5d %-16s %-16s %s%s", $value, $pid, $procname, $type, $symbol, ($stack ne "") ? "\n" . $stack : "\n");
}
# n * log(n)
sub tuples_and_values_of_nested_hash {
my $hash = shift;
my @tuples = ();
my @values = ();
foreach my $key (keys %$hash) {
if (ref $hash->{$key} eq "HASH") {
my $i;
my ($subtuplesref, $subvaluesref) = tuples_and_values_of_nested_hash($hash->{$key});
for ($i = 0; $i < scalar @$subtuplesref; $i++) {
my @subtuple = @{ ${$subtuplesref}[$i] };
my $subvalue = ${$subvaluesref}[$i];
push @tuples, [$key, @subtuple];
push @values, $subvalue;
}
} else {
push @tuples, [$key];
push @values, $hash->{$key};
}
}
my @permutation = sort { $values[$a] <=> $values[$b] } (0..$#values);
@tuples = @tuples[@permutation];
@values = @values[@permutation];
return (\@tuples, \@values);
}
'
/usr/sbin/dtrace -xdisallow_dsym -Cqn "$dtrace" | /usr/bin/perl -w -e "$aggregator"
else
exec /usr/sbin/dtrace -xdisallow_dsym -Cqn "$dtrace"
fi
@brianmichel
Copy link
Author

brianmichel commented Sep 26, 2022

You'll have to enable dtrace for your system first by restarting in recovery mode and running csrutil enable --without dtrace and then restarting again.

After that download this script and chmod +x to run it against locally build binary.

For the probes that are disabled, it seems like the structure of thread_t has changed over the years and whichever fields are trying to be dereferenced no longer exist. You can see which fields do exist by running this command sudo dtrace -n 'BEGIN { print(*curthread); exit(0); }'

After enabling DTrace through the csrutil command listed above you can run this script in the following manner:

./timerfires2 -p <PID>

FB11601840 has been filed with Apple to track getting a blessed version of this for modern versions of macOS.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment