Bug #4740


kstat(1M) prints wrong snaptime

Added by David Pacheco over 8 years ago. Updated over 6 years ago.

cmd - userland programs
Start date:
Due date:
% Done:


Estimated time:
Gerrit CR:
External Bug:


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

        self->z = args[1];

/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().

Actions #1

Updated by David Höppner over 8 years ago

This bug was introduced by me. You plan to provide a patch in illumos-joyent or here? Thanks for the analysis.

Actions #2

Updated by David Pacheco over 8 years ago

No problem. I haven't put together a patch yet because I found this while debugging another issue that I'm still working on.

Actions #3

Updated by Robert Mustacchi over 6 years ago

  • Category set to cmd - userland programs
  • Assignee set to Robert Mustacchi
Actions #4

Updated by Electric Monk over 6 years ago

  • Status changed from New to Closed
  • % Done changed from 0 to 100

git commit 6a19b8666104dbf912da5a4fb193c9c2b29e21bb

commit  6a19b8666104dbf912da5a4fb193c9c2b29e21bb
Author: Robert Mustacchi <>
Date:   2016-03-26T03:27:58.000Z

    4740 kstat(1M) prints wrong snaptime
    Reviewed by: Dave Pacheco <>
    Reviewed by: David Höppner <>
    Reviewed by: Toomas Soome <>
    Approved by: Richard Lowe <>


Also available in: Atom PDF