illumos gate

Here's a D script I've been using to trace kstat_read() invocations in a target process:

#!/usr/sbin/dtrace -s

/*
 * kstat.d: trace kstat_read() calls in the target process and dump details
 * about the kstat that was read.
 */

#pragma D option quiet

pid$target::kstat_read:entry
{
        self->z = args[1];
}

pid$target::kstat_read:return
/self->z && self->z->ks_instance == 0/
{
        printf("kstat_read: %s %s %s %4d %d\\n",
            self->z->ks_module, self->z->ks_name, self->z->ks_class,
            self->z->ks_instance, self->z->ks_snaptime);
        self->z = 0;
}

On SmartOS 20140403T042219Z, I ran this and got this output:

[root@headnode (sf-1) /var/tmp]# ./kstat.d -c 'kstat -p cpu:0:vm:snaptime 1 5'
cpu:0:vm:snaptime       551739.402301749
kstat_read:  kstat_headers     0 551784731060874
kstat_read: cpu vm misc    0 551784741828852

cpu:0:vm:snaptime       551784.741828852
kstat_read: cpu vm misc    0 551785741981082

cpu:0:vm:snaptime       551785.741981082
kstat_read: cpu vm misc    0 551786741974916

cpu:0:vm:snaptime       551786.741974916
kstat_read: cpu vm misc    0 551787741982980

cpu:0:vm:snaptime       551787.741982980
kstat_read: cpu vm misc    0 551788741885671

Note that kstat(1M) prints out 5 snaptimes, and there are 5 kstat_read() calls for the "cpu" kstat, but the snaptimes don't match up. The first snaptime that "kstat" prints was never read by kstat_read(). After that, "kstat" always seems to print the previous kstat_read()'s snaptime with the next one's data.

I believe that's exactly what the code in ks_instances_read() does. For a given kstat_t in the chain, it allocates a new ks_instance_t, copies the "crtime", "snaptime", and "class" into it, appends it to the list of instances that it will print out later, reads the kstat_t, and then copies the named values stored in ks_data. I think it should be copying "snaptime" after the kstat_read().