Subject: bin/10201: getrusage microseconds can go backwards in time!
To: None <gnats-bugs@gnats.netbsd.org>
From: None <refling@comet.lbl.gov>
List: netbsd-bugs
Date: 05/25/2000 11:54:13
>Number:         10201
>Category:       bin
>Synopsis:       getrusage microseconds can go backwards in time!
>Confidential:   no
>Severity:       serious
>Priority:       low
>Responsible:    bin-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Thu May 25 11:55:00 PDT 2000
>Closed-Date:
>Last-Modified:
>Originator:     John P. Refling
>Release:        1.4.2
>Organization:
LBNL
>Environment:
i386 and sparc

>Description:
getrusage microseconds can go backwards in time!

s micro delta
~ ~~~~~ ~~~~~
0 24777 24777
0 31365 6588
0 31611 246
0 31839 228
0 32065 226
0 32294 229
0 32520 226
0 32746 226
...
0 44786 255
0 45039 253
0 48338 3299
0 48628 290
0 48902 274
...
0 54697 270
0 54969 272
0 55240 271
0 58332 3092
0 58724 392
0 59011 287
0 59294 283
...
0 132346 355
0 132701 355
0 133054 353
0 133408 354
0 126362 -7046 BAD
0 126725 363
0 131857 335
0 132191 334
0 132527 336
0 132866 339
0 133204 338
0 126546 -6658 BAD
0 126895 349
0 127209 314
0 127526 317
0 127846 320
...
0 131779 320
0 132097 318
0 132414 317
0 132731 317
0 126431 -6300 BAD
0 126758 327
0 127062 304
...
0 131973 303
0 132272 299
0 132569 297
0 126564 -6005 BAD
0 126876 312
0 127164 288
...
0 171575 313
0 171886 311
0 174797 2911
0 175134 337
0 175453 319
0 175771 318
0 176089 318

etc

>How-To-Repeat:
run the following program:

// John P. Refling ... demonstrates problems with getrusage
// on my sparc LX and i386 on NetBSD.  Not sure what other ports may
// have this problem, or what other sparc machines may have it.
//
// Basically, the microseconds part can occasionally vary
// drastically, both forward in time and BACKWARDS!
//

#include <sys/types.h>
#include <sys/time.h>
#include <sys/resource.h>

// no problems here on LX: #define LOOP 100000L
// problems #define LOOP 10000L
// problems #define LOOP 1000L
#define LOOP 100L

main() {
    long i, sec, psec = -1L, usec, pusec = 0L, diff;
    struct rusage ru;
    for (;;) {
        getrusage( RUSAGE_SELF, &ru );
        usec = ru.ru_utime.tv_usec;
        sec = ru.ru_utime.tv_sec;
        diff = usec - pusec;

        // neg diff ok if seconds changed
        if (diff >= 0 || sec != psec) {} // printf("%ld %ld %ld\n", sec, usec, usec - pusec);
        else printf("%ld %ld %ld BAD\n", sec, usec, diff);
     
        // store current, soon to be prior, for next iteration and delay
        psec = sec;
        pusec = usec;
        for (i = 0; i < LOOP; i++);
    }
}

>Fix:


>Release-Note:
>Audit-Trail:
>Unformatted: