monotonic clock going backwards?

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

monotonic clock going backwards?

David Hill-3
Hello -

I noticed some negative roundtrip times when running traceroute, which
uses the monotonic clock to calculate the RTT.

If I run the following code, it eventually bombs.  It bombs quick if I
launch Firefox.

timespeccmp failed
tp1 s:103780 n:63101042
tp2 s:103779 n:761117849


----


#include <sys/time.h>
#include <time.h>
#include <stdlib.h>
#include <stdio.h>

int
main(void)
{
         int r;
         struct timespec tp1, tp2, tout;

         tout.tv_sec = 0;
         tout.tv_nsec = 100000;

         for (;;) {
                 r = clock_gettime(CLOCK_MONOTONIC, &tp1);
                 if (r == -1) {
                         perror("clock_gettime");
                         exit(-1);
                 }

                 nanosleep(&tout, NULL);

                 r = clock_gettime(CLOCK_MONOTONIC, &tp2);
                 if (r == -1) {
                         perror("clock_gettime");
                         exit(-1);
                 }

                 // tp1 should never be larger than tp2
                 r = timespeccmp(&tp1, &tp2, >);
                 if (r == 1) {
                         printf("timespeccmp failed\n");
                         printf("tp1 s:%lld n:%ld\n", tp1.tv_sec,
tp1.tv_nsec);
                         printf("tp2 s:%lld n:%ld\n", tp2.tv_sec,
tp2.tv_nsec);
                         exit(-1);
                 }
         }

         return 0;
}

Reply | Threaded
Open this post in threaded view
|

Re: monotonic clock going backwards?

Scott Cheloha
On Wed, Jun 05, 2019 at 08:33:56PM -0400, David Hill wrote:

> Hello -
>
> I noticed some negative roundtrip times when running traceroute, which uses
> the monotonic clock to calculate the RTT.
>
> If I run the following code, it eventually bombs.?? It bombs quick if I
> launch Firefox.
>
> timespeccmp failed
> tp1 s:103780 n:63101042
> tp2 s:103779 n:761117849

please share your dmesg and the output of

        sysctl kern.clockrate kern.timecounter

Could you also share the output when you run the following code?
With and without firefox running?  Curious about how frequently
this happens.

#include <sys/time.h>

#include <err.h>
#include <stdio.h>
#include <time.h>

int
main(void)
{
        struct timespec t0, t1, timeout;

        timeout.tv_sec = 0;
        timeout.tv_nsec = 100000;

        for (;;) {
                clock_gettime(CLOCK_MONOTONIC, &t0);
                if (nanosleep(&timeout, NULL) == -1)
                        err(1, "nanosleep");
                clock_gettime(CLOCK_MONOTONIC, &t1);
                if (timespeccmp(&t0, &t1, >)) {
                        printf("%lld.%09ld precedes %lld.%09ld\n",
                            t1.tv_sec, t1.tv_nsec, t0.tv_sec, t0.tv_nsec);
                }
        }

        return 0;
}

Reply | Threaded
Open this post in threaded view
|

Re: monotonic clock going backwards?

David Hill-3

On 6/6/19 6:56 AM, Scott Cheloha wrote:

> On Wed, Jun 05, 2019 at 08:33:56PM -0400, David Hill wrote:
>> Hello -
>>
>> I noticed some negative roundtrip times when running traceroute, which uses
>> the monotonic clock to calculate the RTT.
>>
>> If I run the following code, it eventually bombs.?? It bombs quick if I
>> launch Firefox.
>>
>> timespeccmp failed
>> tp1 s:103780 n:63101042
>> tp2 s:103779 n:761117849
> please share your dmesg and the output of
>
> sysctl kern.clockrate kern.timecounter
>
> Could you also share the output when you run the following code?
> With and without firefox running?  Curious about how frequently
> this happens.
>
> #include <sys/time.h>
>
> #include <err.h>
> #include <stdio.h>
> #include <time.h>
>
> int
> main(void)
> {
> struct timespec t0, t1, timeout;
>
> timeout.tv_sec = 0;
> timeout.tv_nsec = 100000;
>
> for (;;) {
> clock_gettime(CLOCK_MONOTONIC, &t0);
> if (nanosleep(&timeout, NULL) == -1)
> err(1, "nanosleep");
> clock_gettime(CLOCK_MONOTONIC, &t1);
> if (timespeccmp(&t0, &t1, >)) {
> printf("%lld.%09ld precedes %lld.%09ld\n",
>    t1.tv_sec, t1.tv_nsec, t0.tv_sec, t0.tv_nsec);
> }
> }
>
> return 0;
> }
>

$ sysctl kern.clockrate kern.timecounter
kern.clockrate=tick = 10000, tickadj = 40, hz = 100, profhz = 100,
stathz = 100
kern.timecounter.tick=1
kern.timecounter.timestepwarnings=0
kern.timecounter.hardware=tsc
kern.timecounter.choice=i8254(0) acpihpet0(1000) tsc(2000) acpitimer0(1000)

146259.148543164 precedes 146259.450584680
146259.488592813 precedes 146259.790556528
146259.808566236 precedes 146260.110528202
146261.148476141 precedes 146261.450398822
146262.888279505 precedes 146263.190240715
146263.887431808 precedes 146264.189435801
146274.487159451 precedes 146274.789148187
146278.186820816 precedes 146278.488803756
146279.546680181 precedes 146279.848674138
146284.326305557 precedes 146284.628224696
146285.426154861 precedes 146285.728066901
146287.885921929 precedes 146288.187826688
146289.985763711 precedes 146290.287731233
146290.985659041 precedes 146291.287640302
146293.985348615 precedes 146294.287327519
146295.465186742 precedes 146295.767218516
146295.885156426 precedes 146296.187140717
146298.544907956 precedes 146298.846882759
146298.644894308 precedes 146298.946889142

OpenBSD 6.5-current (GENERIC.MP) #27: Tue Jun  4 15:36:14 EDT 2019
[hidden email]:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 8418242560 (8028MB)
avail mem = 8152993792 (7775MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.8 @ 0x9a565000 (49 entries)
bios0: vendor American Megatrends Inc. version "X420UA.204" date 11/16/2018
bios0: ASUSTeK COMPUTER INC. VivoBook_ASUSLaptop X420UA
acpi0 at bios0: rev 2
acpi0: sleep states S0 S3 S4 S5
acpi0: tables DSDT FACP APIC FPDT FIDT ECDT MCFG SSDT SSDT SSDT MSDM
SSDT HPET SSDT UEFI SSDT LPIT SSDT SSDT SSDT SSDT DBGP DBG2 DMAR NHLT
BGRT TPM2 WSMT
acpi0: wakeup devices PXSX(S4) RP06(S4) GLAN(S4) XHC_(S3) XDCI(S4) HDAS(S4)
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3393.27 MHz, 06-8e-0a
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 23MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
cpu1 at mainbus0: apid 2 (application processor)
cpu1: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu1:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 0, core 1, package 0
cpu2 at mainbus0: apid 4 (application processor)
cpu2: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu2:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu2: 256KB 64b/line 8-way L2 cache
cpu2: smt 0, core 2, package 0
cpu3 at mainbus0: apid 6 (application processor)
cpu3: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu3:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu3: 256KB 64b/line 8-way L2 cache
cpu3: smt 0, core 3, package 0
cpu4 at mainbus0: apid 1 (application processor)
cpu4: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu4:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu4: 256KB 64b/line 8-way L2 cache
cpu4: smt 1, core 0, package 0
cpu5 at mainbus0: apid 3 (application processor)
cpu5: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu5:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu5: 256KB 64b/line 8-way L2 cache
cpu5: smt 1, core 1, package 0
cpu6 at mainbus0: apid 5 (application processor)
cpu6: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu6:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu6: 256KB 64b/line 8-way L2 cache
cpu6: smt 1, core 2, package 0
cpu7 at mainbus0: apid 7 (application processor)
cpu7: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
cpu7:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
cpu7: 256KB 64b/line 8-way L2 cache
cpu7: smt 1, core 3, package 0
ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 120 pins
acpiec0 at acpi0
acpimcfg0 at acpi0
acpimcfg0: addr 0xf0000000, bus 0-127
acpihpet0 at acpi0: 23999999 Hz
acpiprt0 at acpi0: bus 0 (PCI0)
acpiprt1 at acpi0: bus -1 (PEG0)
acpiprt2 at acpi0: bus -1 (PEG1)
acpiprt3 at acpi0: bus -1 (PEG2)
acpiprt4 at acpi0: bus -1 (RP09)
acpiprt5 at acpi0: bus -1 (RP10)
acpiprt6 at acpi0: bus -1 (RP11)
acpiprt7 at acpi0: bus -1 (RP12)
acpiprt8 at acpi0: bus -1 (RP13)
acpiprt9 at acpi0: bus -1 (RP01)
acpiprt10 at acpi0: bus -1 (RP02)
acpiprt11 at acpi0: bus -1 (RP03)
acpiprt12 at acpi0: bus -1 (RP04)
acpiprt13 at acpi0: bus -1 (RP05)
acpiprt14 at acpi0: bus 1 (RP06)
acpiprt15 at acpi0: bus -1 (RP07)
acpiprt16 at acpi0: bus -1 (RP08)
acpiprt17 at acpi0: bus -1 (RP17)
acpiprt18 at acpi0: bus -1 (RP18)
acpiprt19 at acpi0: bus -1 (RP19)
acpiprt20 at acpi0: bus -1 (RP20)
acpiprt21 at acpi0: bus -1 (RP21)
acpiprt22 at acpi0: bus -1 (RP22)
acpiprt23 at acpi0: bus -1 (RP23)
acpiprt24 at acpi0: bus -1 (RP24)
acpiprt25 at acpi0: bus -1 (RP14)
acpiprt26 at acpi0: bus -1 (RP15)
acpiprt27 at acpi0: bus -1 (RP16)
acpiec at acpi0 not configured
acpicpu0 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu1 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu2 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu3 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu4 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu5 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu6 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpicpu7 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
C1(1000@1 mwait.1), PSS
acpitz0 at acpi0: critical temperature is 103 degC
acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
acpicmos0 at acpi0
acpiac0 at acpi0: AC unit online
acpibtn0 at acpi0: LID_
acpibat0 at acpi0: BAT0 model "ASUS Battery" serial   type LIon oem
"ASUSTeK"
"INT3403" at acpi0 not configured
"INT3403" at acpi0 not configured
"INT3403" at acpi0 not configured
"INT3403" at acpi0 not configured
"ATK3001" at acpi0 not configured
"INT344B" at acpi0 not configured
"ELAN1200" at acpi0 not configured
acpibtn1 at acpi0: SLPB
"INT33A1" at acpi0 not configured
acpibtn2 at acpi0: PWRB
"MSFT0101" at acpi0 not configured
"ASUS7000" at acpi0 not configured
"PNP0C14" at acpi0 not configured
"ASUS1000" at acpi0 not configured
"INT3400" at acpi0 not configured
acpivideo0 at acpi0: GFX0
acpivout0 at acpivideo0: DD1F
cpu0: using VERW MDS workaround (except on vmm entry)
cpu0: Enhanced SpeedStep 3393 MHz: speeds: 1801, 1800, 1700, 1600, 1500,
1400, 1300, 1200, 1100, 1000, 900, 800, 700, 600, 500, 400 MHz
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel Core 8G Host" rev 0x08
inteldrm0 at pci0 dev 2 function 0 "Intel UHD Graphics 620" rev 0x07
drm0 at inteldrm0
inteldrm0: msi
"Intel Core 6G Thermal" rev 0x08 at pci0 dev 4 function 0 not configured
xhci0 at pci0 dev 20 function 0 "Intel 100 Series xHCI" rev 0x21: msi,
xHCI 1.0
usb0 at xhci0: USB revision 3.0
uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev
3.00/1.00 addr 1
pchtemp0 at pci0 dev 20 function 2 "Intel 100 Series Thermal" rev 0x21
dwiic0 at pci0 dev 21 function 0 "Intel 100 Series I2C" rev 0x21: apic 2
int 16
iic0 at dwiic0
dwiic1 at pci0 dev 21 function 1 "Intel 100 Series I2C" rev 0x21: apic 2
int 17
iic1 at dwiic1
ihidev0 at iic1 addr 0x15 (polling), vendor 0x4f3 product 0x30ce, ELAN1200
ihidev0: 11 report ids
imt0 at ihidev0: clickpad, 5 contacts
wsmouse0 at imt0 mux 0
"Intel 100 Series MEI" rev 0x21 at pci0 dev 22 function 0 not configured
ahci0 at pci0 dev 23 function 0 "Intel 100 Series AHCI" rev 0x21: msi,
AHCI 1.3.1
ahci0: PHY offline on port 1
ahci0: port 2: 6.0Gb/s
scsibus1 at ahci0: 32 targets
sd0 at scsibus1 targ 2 lun 0: <ATA, SanDisk SD9SN8W1, X610> SCSI3
0/direct fixed naa.5001b448b9007e6f
sd0: 122104MB, 512 bytes/sector, 250069680 sectors, thin
ppb0 at pci0 dev 28 function 0 "Intel 100 Series PCIE" rev 0xf1: msi
pci1 at ppb0 bus 1
iwm0 at pci1 dev 0 function 0 "Intel Dual Band Wireless-AC 8265" rev
0x78, msi
"Intel 100 Series UART" rev 0x21 at pci0 dev 30 function 0 not configured
"Intel 100 Series SPI" rev 0x21 at pci0 dev 30 function 2 not configured
pcib0 at pci0 dev 31 function 0 "Intel 200 Series LPC" rev 0x21
"Intel 100 Series PMC" rev 0x21 at pci0 dev 31 function 2 not configured
azalia0 at pci0 dev 31 function 3 "Intel 200 Series HD Audio" rev 0x21: msi
azalia0: codecs: Realtek/0x0256, Intel/0x280b, using Realtek/0x0256
audio0 at azalia0
ichiic0 at pci0 dev 31 function 4 "Intel 100 Series SMBus" rev 0x21:
apic 2 int 16
iic2 at ichiic0
isa0 at pcib0
isadma0 at isa0
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0: console keyboard
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
vmm0 at mainbus0: VMX/EPT
efifb at mainbus0 not configured
vscsi0 at root
scsibus2 at vscsi0: 256 targets
softraid0 at root
scsibus3 at softraid0: 256 targets
root on sd0a (047aa5e482271013.a) swap on sd0b dump on sd0b
inteldrm0: 1920x1080, 32bpp
wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
wsdisplay0: screen 1-5 added (std, vt100 emulation)

Reply | Threaded
Open this post in threaded view
|

Re: monotonic clock going backwards?

Mark Kettenis
> From: David Hill <[hidden email]>
> Date: Thu, 6 Jun 2019 08:22:06 -0400
>
> On 6/6/19 6:56 AM, Scott Cheloha wrote:
> > On Wed, Jun 05, 2019 at 08:33:56PM -0400, David Hill wrote:
> >> Hello -
> >>
> >> I noticed some negative roundtrip times when running traceroute, which uses
> >> the monotonic clock to calculate the RTT.
> >>
> >> If I run the following code, it eventually bombs.?? It bombs quick if I
> >> launch Firefox.
> >>
> >> timespeccmp failed
> >> tp1 s:103780 n:63101042
> >> tp2 s:103779 n:761117849
> > please share your dmesg and the output of
> >
> > sysctl kern.clockrate kern.timecounter
> >
> > Could you also share the output when you run the following code?
> > With and without firefox running?  Curious about how frequently
> > this happens.
> >
> > #include <sys/time.h>
> >
> > #include <err.h>
> > #include <stdio.h>
> > #include <time.h>
> >
> > int
> > main(void)
> > {
> > struct timespec t0, t1, timeout;
> >
> > timeout.tv_sec = 0;
> > timeout.tv_nsec = 100000;
> >
> > for (;;) {
> > clock_gettime(CLOCK_MONOTONIC, &t0);
> > if (nanosleep(&timeout, NULL) == -1)
> > err(1, "nanosleep");
> > clock_gettime(CLOCK_MONOTONIC, &t1);
> > if (timespeccmp(&t0, &t1, >)) {
> > printf("%lld.%09ld precedes %lld.%09ld\n",
> >    t1.tv_sec, t1.tv_nsec, t0.tv_sec, t0.tv_nsec);
> > }
> > }
> >
> > return 0;
> > }
> >
>
> $ sysctl kern.clockrate kern.timecounter
> kern.clockrate=tick = 10000, tickadj = 40, hz = 100, profhz = 100,
> stathz = 100
> kern.timecounter.tick=1
> kern.timecounter.timestepwarnings=0
> kern.timecounter.hardware=tsc
> kern.timecounter.choice=i8254(0) acpihpet0(1000) tsc(2000) acpitimer0(1000)
>
> 146259.148543164 precedes 146259.450584680
> 146259.488592813 precedes 146259.790556528
> 146259.808566236 precedes 146260.110528202
> 146261.148476141 precedes 146261.450398822
> 146262.888279505 precedes 146263.190240715
> 146263.887431808 precedes 146264.189435801
> 146274.487159451 precedes 146274.789148187
> 146278.186820816 precedes 146278.488803756
> 146279.546680181 precedes 146279.848674138
> 146284.326305557 precedes 146284.628224696
> 146285.426154861 precedes 146285.728066901
> 146287.885921929 precedes 146288.187826688
> 146289.985763711 precedes 146290.287731233
> 146290.985659041 precedes 146291.287640302
> 146293.985348615 precedes 146294.287327519
> 146295.465186742 precedes 146295.767218516
> 146295.885156426 precedes 146296.187140717
> 146298.544907956 precedes 146298.846882759
> 146298.644894308 precedes 146298.946889142

Does this also happen with

kern.timecounter.hardware=acpihpet

?

> OpenBSD 6.5-current (GENERIC.MP) #27: Tue Jun  4 15:36:14 EDT 2019
> [hidden email]:/usr/src/sys/arch/amd64/compile/GENERIC.MP
> real mem = 8418242560 (8028MB)
> avail mem = 8152993792 (7775MB)
> mpath0 at root
> scsibus0 at mpath0: 256 targets
> mainbus0 at root
> bios0 at mainbus0: SMBIOS rev. 2.8 @ 0x9a565000 (49 entries)
> bios0: vendor American Megatrends Inc. version "X420UA.204" date 11/16/2018
> bios0: ASUSTeK COMPUTER INC. VivoBook_ASUSLaptop X420UA
> acpi0 at bios0: rev 2
> acpi0: sleep states S0 S3 S4 S5
> acpi0: tables DSDT FACP APIC FPDT FIDT ECDT MCFG SSDT SSDT SSDT MSDM
> SSDT HPET SSDT UEFI SSDT LPIT SSDT SSDT SSDT SSDT DBGP DBG2 DMAR NHLT
> BGRT TPM2 WSMT
> acpi0: wakeup devices PXSX(S4) RP06(S4) GLAN(S4) XHC_(S3) XDCI(S4) HDAS(S4)
> acpitimer0 at acpi0: 3579545 Hz, 24 bits
> acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
> cpu0 at mainbus0: apid 0 (boot processor)
> cpu0: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3393.27 MHz, 06-8e-0a
> cpu0:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu0: 256KB 64b/line 8-way L2 cache
> cpu0: smt 0, core 0, package 0
> mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
> cpu0: apic clock running at 23MHz
> cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
> cpu1 at mainbus0: apid 2 (application processor)
> cpu1: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu1:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu1: 256KB 64b/line 8-way L2 cache
> cpu1: smt 0, core 1, package 0
> cpu2 at mainbus0: apid 4 (application processor)
> cpu2: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu2:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu2: 256KB 64b/line 8-way L2 cache
> cpu2: smt 0, core 2, package 0
> cpu3 at mainbus0: apid 6 (application processor)
> cpu3: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu3:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu3: 256KB 64b/line 8-way L2 cache
> cpu3: smt 0, core 3, package 0
> cpu4 at mainbus0: apid 1 (application processor)
> cpu4: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu4:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu4: 256KB 64b/line 8-way L2 cache
> cpu4: smt 1, core 0, package 0
> cpu5 at mainbus0: apid 3 (application processor)
> cpu5: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu5:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu5: 256KB 64b/line 8-way L2 cache
> cpu5: smt 1, core 1, package 0
> cpu6 at mainbus0: apid 5 (application processor)
> cpu6: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu6:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu6: 256KB 64b/line 8-way L2 cache
> cpu6: smt 1, core 2, package 0
> cpu7 at mainbus0: apid 7 (application processor)
> cpu7: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
> cpu7:
> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
> cpu7: 256KB 64b/line 8-way L2 cache
> cpu7: smt 1, core 3, package 0
> ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 120 pins
> acpiec0 at acpi0
> acpimcfg0 at acpi0
> acpimcfg0: addr 0xf0000000, bus 0-127
> acpihpet0 at acpi0: 23999999 Hz
> acpiprt0 at acpi0: bus 0 (PCI0)
> acpiprt1 at acpi0: bus -1 (PEG0)
> acpiprt2 at acpi0: bus -1 (PEG1)
> acpiprt3 at acpi0: bus -1 (PEG2)
> acpiprt4 at acpi0: bus -1 (RP09)
> acpiprt5 at acpi0: bus -1 (RP10)
> acpiprt6 at acpi0: bus -1 (RP11)
> acpiprt7 at acpi0: bus -1 (RP12)
> acpiprt8 at acpi0: bus -1 (RP13)
> acpiprt9 at acpi0: bus -1 (RP01)
> acpiprt10 at acpi0: bus -1 (RP02)
> acpiprt11 at acpi0: bus -1 (RP03)
> acpiprt12 at acpi0: bus -1 (RP04)
> acpiprt13 at acpi0: bus -1 (RP05)
> acpiprt14 at acpi0: bus 1 (RP06)
> acpiprt15 at acpi0: bus -1 (RP07)
> acpiprt16 at acpi0: bus -1 (RP08)
> acpiprt17 at acpi0: bus -1 (RP17)
> acpiprt18 at acpi0: bus -1 (RP18)
> acpiprt19 at acpi0: bus -1 (RP19)
> acpiprt20 at acpi0: bus -1 (RP20)
> acpiprt21 at acpi0: bus -1 (RP21)
> acpiprt22 at acpi0: bus -1 (RP22)
> acpiprt23 at acpi0: bus -1 (RP23)
> acpiprt24 at acpi0: bus -1 (RP24)
> acpiprt25 at acpi0: bus -1 (RP14)
> acpiprt26 at acpi0: bus -1 (RP15)
> acpiprt27 at acpi0: bus -1 (RP16)
> acpiec at acpi0 not configured
> acpicpu0 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu1 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu2 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu3 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu4 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu5 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu6 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpicpu7 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
> C1(1000@1 mwait.1), PSS
> acpitz0 at acpi0: critical temperature is 103 degC
> acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
> acpicmos0 at acpi0
> acpiac0 at acpi0: AC unit online
> acpibtn0 at acpi0: LID_
> acpibat0 at acpi0: BAT0 model "ASUS Battery" serial   type LIon oem
> "ASUSTeK"
> "INT3403" at acpi0 not configured
> "INT3403" at acpi0 not configured
> "INT3403" at acpi0 not configured
> "INT3403" at acpi0 not configured
> "ATK3001" at acpi0 not configured
> "INT344B" at acpi0 not configured
> "ELAN1200" at acpi0 not configured
> acpibtn1 at acpi0: SLPB
> "INT33A1" at acpi0 not configured
> acpibtn2 at acpi0: PWRB
> "MSFT0101" at acpi0 not configured
> "ASUS7000" at acpi0 not configured
> "PNP0C14" at acpi0 not configured
> "ASUS1000" at acpi0 not configured
> "INT3400" at acpi0 not configured
> acpivideo0 at acpi0: GFX0
> acpivout0 at acpivideo0: DD1F
> cpu0: using VERW MDS workaround (except on vmm entry)
> cpu0: Enhanced SpeedStep 3393 MHz: speeds: 1801, 1800, 1700, 1600, 1500,
> 1400, 1300, 1200, 1100, 1000, 900, 800, 700, 600, 500, 400 MHz
> pci0 at mainbus0 bus 0
> pchb0 at pci0 dev 0 function 0 "Intel Core 8G Host" rev 0x08
> inteldrm0 at pci0 dev 2 function 0 "Intel UHD Graphics 620" rev 0x07
> drm0 at inteldrm0
> inteldrm0: msi
> "Intel Core 6G Thermal" rev 0x08 at pci0 dev 4 function 0 not configured
> xhci0 at pci0 dev 20 function 0 "Intel 100 Series xHCI" rev 0x21: msi,
> xHCI 1.0
> usb0 at xhci0: USB revision 3.0
> uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev
> 3.00/1.00 addr 1
> pchtemp0 at pci0 dev 20 function 2 "Intel 100 Series Thermal" rev 0x21
> dwiic0 at pci0 dev 21 function 0 "Intel 100 Series I2C" rev 0x21: apic 2
> int 16
> iic0 at dwiic0
> dwiic1 at pci0 dev 21 function 1 "Intel 100 Series I2C" rev 0x21: apic 2
> int 17
> iic1 at dwiic1
> ihidev0 at iic1 addr 0x15 (polling), vendor 0x4f3 product 0x30ce, ELAN1200
> ihidev0: 11 report ids
> imt0 at ihidev0: clickpad, 5 contacts
> wsmouse0 at imt0 mux 0
> "Intel 100 Series MEI" rev 0x21 at pci0 dev 22 function 0 not configured
> ahci0 at pci0 dev 23 function 0 "Intel 100 Series AHCI" rev 0x21: msi,
> AHCI 1.3.1
> ahci0: PHY offline on port 1
> ahci0: port 2: 6.0Gb/s
> scsibus1 at ahci0: 32 targets
> sd0 at scsibus1 targ 2 lun 0: <ATA, SanDisk SD9SN8W1, X610> SCSI3
> 0/direct fixed naa.5001b448b9007e6f
> sd0: 122104MB, 512 bytes/sector, 250069680 sectors, thin
> ppb0 at pci0 dev 28 function 0 "Intel 100 Series PCIE" rev 0xf1: msi
> pci1 at ppb0 bus 1
> iwm0 at pci1 dev 0 function 0 "Intel Dual Band Wireless-AC 8265" rev
> 0x78, msi
> "Intel 100 Series UART" rev 0x21 at pci0 dev 30 function 0 not configured
> "Intel 100 Series SPI" rev 0x21 at pci0 dev 30 function 2 not configured
> pcib0 at pci0 dev 31 function 0 "Intel 200 Series LPC" rev 0x21
> "Intel 100 Series PMC" rev 0x21 at pci0 dev 31 function 2 not configured
> azalia0 at pci0 dev 31 function 3 "Intel 200 Series HD Audio" rev 0x21: msi
> azalia0: codecs: Realtek/0x0256, Intel/0x280b, using Realtek/0x0256
> audio0 at azalia0
> ichiic0 at pci0 dev 31 function 4 "Intel 100 Series SMBus" rev 0x21:
> apic 2 int 16
> iic2 at ichiic0
> isa0 at pcib0
> isadma0 at isa0
> pckbc0 at isa0 port 0x60/5 irq 1 irq 12
> pckbd0 at pckbc0 (kbd slot)
> wskbd0 at pckbd0: console keyboard
> pcppi0 at isa0 port 0x61
> spkr0 at pcppi0
> vmm0 at mainbus0: VMX/EPT
> efifb at mainbus0 not configured
> vscsi0 at root
> scsibus2 at vscsi0: 256 targets
> softraid0 at root
> scsibus3 at softraid0: 256 targets
> root on sd0a (047aa5e482271013.a) swap on sd0b dump on sd0b
> inteldrm0: 1920x1080, 32bpp
> wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
> wsdisplay0: screen 1-5 added (std, vt100 emulation)
>
>

Reply | Threaded
Open this post in threaded view
|

Re: monotonic clock going backwards?

David Hill-3

On 6/6/19 8:49 AM, Mark Kettenis wrote:

>> From: David Hill <[hidden email]>
>> Date: Thu, 6 Jun 2019 08:22:06 -0400
>>
>> On 6/6/19 6:56 AM, Scott Cheloha wrote:
>>> On Wed, Jun 05, 2019 at 08:33:56PM -0400, David Hill wrote:
>>>> Hello -
>>>>
>>>> I noticed some negative roundtrip times when running traceroute, which uses
>>>> the monotonic clock to calculate the RTT.
>>>>
>>>> If I run the following code, it eventually bombs.?? It bombs quick if I
>>>> launch Firefox.
>>>>
>>>> timespeccmp failed
>>>> tp1 s:103780 n:63101042
>>>> tp2 s:103779 n:761117849
>>> please share your dmesg and the output of
>>>
>>> sysctl kern.clockrate kern.timecounter
>>>
>>> Could you also share the output when you run the following code?
>>> With and without firefox running?  Curious about how frequently
>>> this happens.
>>>
>>> #include <sys/time.h>
>>>
>>> #include <err.h>
>>> #include <stdio.h>
>>> #include <time.h>
>>>
>>> int
>>> main(void)
>>> {
>>> struct timespec t0, t1, timeout;
>>>
>>> timeout.tv_sec = 0;
>>> timeout.tv_nsec = 100000;
>>>
>>> for (;;) {
>>> clock_gettime(CLOCK_MONOTONIC, &t0);
>>> if (nanosleep(&timeout, NULL) == -1)
>>> err(1, "nanosleep");
>>> clock_gettime(CLOCK_MONOTONIC, &t1);
>>> if (timespeccmp(&t0, &t1, >)) {
>>> printf("%lld.%09ld precedes %lld.%09ld\n",
>>>    t1.tv_sec, t1.tv_nsec, t0.tv_sec, t0.tv_nsec);
>>> }
>>> }
>>>
>>> return 0;
>>> }
>>>
>> $ sysctl kern.clockrate kern.timecounter
>> kern.clockrate=tick = 10000, tickadj = 40, hz = 100, profhz = 100,
>> stathz = 100
>> kern.timecounter.tick=1
>> kern.timecounter.timestepwarnings=0
>> kern.timecounter.hardware=tsc
>> kern.timecounter.choice=i8254(0) acpihpet0(1000) tsc(2000) acpitimer0(1000)
>>
>> 146259.148543164 precedes 146259.450584680
>> 146259.488592813 precedes 146259.790556528
>> 146259.808566236 precedes 146260.110528202
>> 146261.148476141 precedes 146261.450398822
>> 146262.888279505 precedes 146263.190240715
>> 146263.887431808 precedes 146264.189435801
>> 146274.487159451 precedes 146274.789148187
>> 146278.186820816 precedes 146278.488803756
>> 146279.546680181 precedes 146279.848674138
>> 146284.326305557 precedes 146284.628224696
>> 146285.426154861 precedes 146285.728066901
>> 146287.885921929 precedes 146288.187826688
>> 146289.985763711 precedes 146290.287731233
>> 146290.985659041 precedes 146291.287640302
>> 146293.985348615 precedes 146294.287327519
>> 146295.465186742 precedes 146295.767218516
>> 146295.885156426 precedes 146296.187140717
>> 146298.544907956 precedes 146298.846882759
>> 146298.644894308 precedes 146298.946889142
> Does this also happen with
>
> kern.timecounter.hardware=acpihpet
>
> ?

Ran the code with kern.timecounter.hardware=acpihpet0 for 10 minutes
without any output.

With the code still running, I switched to tsc and starting seeing output:

151944.345840447 precedes 151944.647753895
151944.525774690 precedes 151944.827681380
151946.405553296 precedes 151946.707533012

The output stops as soon as I switch back to acpihpet0.

I will add that to my /etc/sysctl.conf.

Thank you.


>
>> OpenBSD 6.5-current (GENERIC.MP) #27: Tue Jun  4 15:36:14 EDT 2019
>> [hidden email]:/usr/src/sys/arch/amd64/compile/GENERIC.MP
>> real mem = 8418242560 (8028MB)
>> avail mem = 8152993792 (7775MB)
>> mpath0 at root
>> scsibus0 at mpath0: 256 targets
>> mainbus0 at root
>> bios0 at mainbus0: SMBIOS rev. 2.8 @ 0x9a565000 (49 entries)
>> bios0: vendor American Megatrends Inc. version "X420UA.204" date 11/16/2018
>> bios0: ASUSTeK COMPUTER INC. VivoBook_ASUSLaptop X420UA
>> acpi0 at bios0: rev 2
>> acpi0: sleep states S0 S3 S4 S5
>> acpi0: tables DSDT FACP APIC FPDT FIDT ECDT MCFG SSDT SSDT SSDT MSDM
>> SSDT HPET SSDT UEFI SSDT LPIT SSDT SSDT SSDT SSDT DBGP DBG2 DMAR NHLT
>> BGRT TPM2 WSMT
>> acpi0: wakeup devices PXSX(S4) RP06(S4) GLAN(S4) XHC_(S3) XDCI(S4) HDAS(S4)
>> acpitimer0 at acpi0: 3579545 Hz, 24 bits
>> acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
>> cpu0 at mainbus0: apid 0 (boot processor)
>> cpu0: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3393.27 MHz, 06-8e-0a
>> cpu0:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu0: 256KB 64b/line 8-way L2 cache
>> cpu0: smt 0, core 0, package 0
>> mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
>> cpu0: apic clock running at 23MHz
>> cpu0: mwait min=64, max=64, C-substates=0.2.1.2.4.1.1.1, IBE
>> cpu1 at mainbus0: apid 2 (application processor)
>> cpu1: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu1:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu1: 256KB 64b/line 8-way L2 cache
>> cpu1: smt 0, core 1, package 0
>> cpu2 at mainbus0: apid 4 (application processor)
>> cpu2: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu2:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu2: 256KB 64b/line 8-way L2 cache
>> cpu2: smt 0, core 2, package 0
>> cpu3 at mainbus0: apid 6 (application processor)
>> cpu3: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu3:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu3: 256KB 64b/line 8-way L2 cache
>> cpu3: smt 0, core 3, package 0
>> cpu4 at mainbus0: apid 1 (application processor)
>> cpu4: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu4:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu4: 256KB 64b/line 8-way L2 cache
>> cpu4: smt 1, core 0, package 0
>> cpu5 at mainbus0: apid 3 (application processor)
>> cpu5: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu5:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu5: 256KB 64b/line 8-way L2 cache
>> cpu5: smt 1, core 1, package 0
>> cpu6 at mainbus0: apid 5 (application processor)
>> cpu6: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu6:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu6: 256KB 64b/line 8-way L2 cache
>> cpu6: smt 1, core 2, package 0
>> cpu7 at mainbus0: apid 7 (application processor)
>> cpu7: Intel(R) Core(TM) i5-8250U CPU @ 1.60GHz, 3392.09 MHz, 06-8e-0a
>> cpu7:
>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,EST,TM2,S
>> SSE3,SDBG,FMA3,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,RDTSCP,LONG,LAHF,ABM,3DNOWP,PERF,ITSC,FSGSBASE,SGX,BMI
>> 1,AVX2,SMEP,BMI2,ERMS,INVPCID,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PT,MD_CLEAR,TSXFA,IBRS,IBPB,STIBP,L1DF,SSBD,SENSOR,ARAT,XSAVEOPT,XSAVEC,XGETBV1,XSAVES,MELTDOWN
>> cpu7: 256KB 64b/line 8-way L2 cache
>> cpu7: smt 1, core 3, package 0
>> ioapic0 at mainbus0: apid 2 pa 0xfec00000, version 20, 120 pins
>> acpiec0 at acpi0
>> acpimcfg0 at acpi0
>> acpimcfg0: addr 0xf0000000, bus 0-127
>> acpihpet0 at acpi0: 23999999 Hz
>> acpiprt0 at acpi0: bus 0 (PCI0)
>> acpiprt1 at acpi0: bus -1 (PEG0)
>> acpiprt2 at acpi0: bus -1 (PEG1)
>> acpiprt3 at acpi0: bus -1 (PEG2)
>> acpiprt4 at acpi0: bus -1 (RP09)
>> acpiprt5 at acpi0: bus -1 (RP10)
>> acpiprt6 at acpi0: bus -1 (RP11)
>> acpiprt7 at acpi0: bus -1 (RP12)
>> acpiprt8 at acpi0: bus -1 (RP13)
>> acpiprt9 at acpi0: bus -1 (RP01)
>> acpiprt10 at acpi0: bus -1 (RP02)
>> acpiprt11 at acpi0: bus -1 (RP03)
>> acpiprt12 at acpi0: bus -1 (RP04)
>> acpiprt13 at acpi0: bus -1 (RP05)
>> acpiprt14 at acpi0: bus 1 (RP06)
>> acpiprt15 at acpi0: bus -1 (RP07)
>> acpiprt16 at acpi0: bus -1 (RP08)
>> acpiprt17 at acpi0: bus -1 (RP17)
>> acpiprt18 at acpi0: bus -1 (RP18)
>> acpiprt19 at acpi0: bus -1 (RP19)
>> acpiprt20 at acpi0: bus -1 (RP20)
>> acpiprt21 at acpi0: bus -1 (RP21)
>> acpiprt22 at acpi0: bus -1 (RP22)
>> acpiprt23 at acpi0: bus -1 (RP23)
>> acpiprt24 at acpi0: bus -1 (RP24)
>> acpiprt25 at acpi0: bus -1 (RP14)
>> acpiprt26 at acpi0: bus -1 (RP15)
>> acpiprt27 at acpi0: bus -1 (RP16)
>> acpiec at acpi0 not configured
>> acpicpu0 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu1 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu2 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu3 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu4 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu5 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu6 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpicpu7 at acpi0: C3(200@1034 mwait.1@0x60), C2(200@151 mwait.1@0x33),
>> C1(1000@1 mwait.1), PSS
>> acpitz0 at acpi0: critical temperature is 103 degC
>> acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
>> acpicmos0 at acpi0
>> acpiac0 at acpi0: AC unit online
>> acpibtn0 at acpi0: LID_
>> acpibat0 at acpi0: BAT0 model "ASUS Battery" serial   type LIon oem
>> "ASUSTeK"
>> "INT3403" at acpi0 not configured
>> "INT3403" at acpi0 not configured
>> "INT3403" at acpi0 not configured
>> "INT3403" at acpi0 not configured
>> "ATK3001" at acpi0 not configured
>> "INT344B" at acpi0 not configured
>> "ELAN1200" at acpi0 not configured
>> acpibtn1 at acpi0: SLPB
>> "INT33A1" at acpi0 not configured
>> acpibtn2 at acpi0: PWRB
>> "MSFT0101" at acpi0 not configured
>> "ASUS7000" at acpi0 not configured
>> "PNP0C14" at acpi0 not configured
>> "ASUS1000" at acpi0 not configured
>> "INT3400" at acpi0 not configured
>> acpivideo0 at acpi0: GFX0
>> acpivout0 at acpivideo0: DD1F
>> cpu0: using VERW MDS workaround (except on vmm entry)
>> cpu0: Enhanced SpeedStep 3393 MHz: speeds: 1801, 1800, 1700, 1600, 1500,
>> 1400, 1300, 1200, 1100, 1000, 900, 800, 700, 600, 500, 400 MHz
>> pci0 at mainbus0 bus 0
>> pchb0 at pci0 dev 0 function 0 "Intel Core 8G Host" rev 0x08
>> inteldrm0 at pci0 dev 2 function 0 "Intel UHD Graphics 620" rev 0x07
>> drm0 at inteldrm0
>> inteldrm0: msi
>> "Intel Core 6G Thermal" rev 0x08 at pci0 dev 4 function 0 not configured
>> xhci0 at pci0 dev 20 function 0 "Intel 100 Series xHCI" rev 0x21: msi,
>> xHCI 1.0
>> usb0 at xhci0: USB revision 3.0
>> uhub0 at usb0 configuration 1 interface 0 "Intel xHCI root hub" rev
>> 3.00/1.00 addr 1
>> pchtemp0 at pci0 dev 20 function 2 "Intel 100 Series Thermal" rev 0x21
>> dwiic0 at pci0 dev 21 function 0 "Intel 100 Series I2C" rev 0x21: apic 2
>> int 16
>> iic0 at dwiic0
>> dwiic1 at pci0 dev 21 function 1 "Intel 100 Series I2C" rev 0x21: apic 2
>> int 17
>> iic1 at dwiic1
>> ihidev0 at iic1 addr 0x15 (polling), vendor 0x4f3 product 0x30ce, ELAN1200
>> ihidev0: 11 report ids
>> imt0 at ihidev0: clickpad, 5 contacts
>> wsmouse0 at imt0 mux 0
>> "Intel 100 Series MEI" rev 0x21 at pci0 dev 22 function 0 not configured
>> ahci0 at pci0 dev 23 function 0 "Intel 100 Series AHCI" rev 0x21: msi,
>> AHCI 1.3.1
>> ahci0: PHY offline on port 1
>> ahci0: port 2: 6.0Gb/s
>> scsibus1 at ahci0: 32 targets
>> sd0 at scsibus1 targ 2 lun 0: <ATA, SanDisk SD9SN8W1, X610> SCSI3
>> 0/direct fixed naa.5001b448b9007e6f
>> sd0: 122104MB, 512 bytes/sector, 250069680 sectors, thin
>> ppb0 at pci0 dev 28 function 0 "Intel 100 Series PCIE" rev 0xf1: msi
>> pci1 at ppb0 bus 1
>> iwm0 at pci1 dev 0 function 0 "Intel Dual Band Wireless-AC 8265" rev
>> 0x78, msi
>> "Intel 100 Series UART" rev 0x21 at pci0 dev 30 function 0 not configured
>> "Intel 100 Series SPI" rev 0x21 at pci0 dev 30 function 2 not configured
>> pcib0 at pci0 dev 31 function 0 "Intel 200 Series LPC" rev 0x21
>> "Intel 100 Series PMC" rev 0x21 at pci0 dev 31 function 2 not configured
>> azalia0 at pci0 dev 31 function 3 "Intel 200 Series HD Audio" rev 0x21: msi
>> azalia0: codecs: Realtek/0x0256, Intel/0x280b, using Realtek/0x0256
>> audio0 at azalia0
>> ichiic0 at pci0 dev 31 function 4 "Intel 100 Series SMBus" rev 0x21:
>> apic 2 int 16
>> iic2 at ichiic0
>> isa0 at pcib0
>> isadma0 at isa0
>> pckbc0 at isa0 port 0x60/5 irq 1 irq 12
>> pckbd0 at pckbc0 (kbd slot)
>> wskbd0 at pckbd0: console keyboard
>> pcppi0 at isa0 port 0x61
>> spkr0 at pcppi0
>> vmm0 at mainbus0: VMX/EPT
>> efifb at mainbus0 not configured
>> vscsi0 at root
>> scsibus2 at vscsi0: 256 targets
>> softraid0 at root
>> scsibus3 at softraid0: 256 targets
>> root on sd0a (047aa5e482271013.a) swap on sd0b dump on sd0b
>> inteldrm0: 1920x1080, 32bpp
>> wsdisplay0 at inteldrm0 mux 1: console (std, vt100 emulation), using wskbd0
>> wsdisplay0: screen 1-5 added (std, vt100 emulation)
>>
>>

Reply | Threaded
Open this post in threaded view
|

Re: monotonic clock going backwards?

Mark Kettenis
> From: David Hill <[hidden email]>
> Date: Thu, 6 Jun 2019 09:55:00 -0400
>
> On 6/6/19 8:49 AM, Mark Kettenis wrote:
> >> From: David Hill <[hidden email]>
> >> Date: Thu, 6 Jun 2019 08:22:06 -0400
> >>
> >> On 6/6/19 6:56 AM, Scott Cheloha wrote:
> >>> On Wed, Jun 05, 2019 at 08:33:56PM -0400, David Hill wrote:
> >>>> Hello -
> >>>>
> >>>> I noticed some negative roundtrip times when running traceroute, which uses
> >>>> the monotonic clock to calculate the RTT.
> >>>>
> >>>> If I run the following code, it eventually bombs.?? It bombs quick if I
> >>>> launch Firefox.
> >>>>
> >>>> timespeccmp failed
> >>>> tp1 s:103780 n:63101042
> >>>> tp2 s:103779 n:761117849
> >>> please share your dmesg and the output of
> >>>
> >>> sysctl kern.clockrate kern.timecounter
> >>>
> >>> Could you also share the output when you run the following code?
> >>> With and without firefox running?  Curious about how frequently
> >>> this happens.
> >>>
> >>> #include <sys/time.h>
> >>>
> >>> #include <err.h>
> >>> #include <stdio.h>
> >>> #include <time.h>
> >>>
> >>> int
> >>> main(void)
> >>> {
> >>> struct timespec t0, t1, timeout;
> >>>
> >>> timeout.tv_sec = 0;
> >>> timeout.tv_nsec = 100000;
> >>>
> >>> for (;;) {
> >>> clock_gettime(CLOCK_MONOTONIC, &t0);
> >>> if (nanosleep(&timeout, NULL) == -1)
> >>> err(1, "nanosleep");
> >>> clock_gettime(CLOCK_MONOTONIC, &t1);
> >>> if (timespeccmp(&t0, &t1, >)) {
> >>> printf("%lld.%09ld precedes %lld.%09ld\n",
> >>>    t1.tv_sec, t1.tv_nsec, t0.tv_sec, t0.tv_nsec);
> >>> }
> >>> }
> >>>
> >>> return 0;
> >>> }
> >>>
> >> $ sysctl kern.clockrate kern.timecounter
> >> kern.clockrate=tick = 10000, tickadj = 40, hz = 100, profhz = 100,
> >> stathz = 100
> >> kern.timecounter.tick=1
> >> kern.timecounter.timestepwarnings=0
> >> kern.timecounter.hardware=tsc
> >> kern.timecounter.choice=i8254(0) acpihpet0(1000) tsc(2000) acpitimer0(1000)
> >>
> >> 146259.148543164 precedes 146259.450584680
> >> 146259.488592813 precedes 146259.790556528
> >> 146259.808566236 precedes 146260.110528202
> >> 146261.148476141 precedes 146261.450398822
> >> 146262.888279505 precedes 146263.190240715
> >> 146263.887431808 precedes 146264.189435801
> >> 146274.487159451 precedes 146274.789148187
> >> 146278.186820816 precedes 146278.488803756
> >> 146279.546680181 precedes 146279.848674138
> >> 146284.326305557 precedes 146284.628224696
> >> 146285.426154861 precedes 146285.728066901
> >> 146287.885921929 precedes 146288.187826688
> >> 146289.985763711 precedes 146290.287731233
> >> 146290.985659041 precedes 146291.287640302
> >> 146293.985348615 precedes 146294.287327519
> >> 146295.465186742 precedes 146295.767218516
> >> 146295.885156426 precedes 146296.187140717
> >> 146298.544907956 precedes 146298.846882759
> >> 146298.644894308 precedes 146298.946889142
> > Does this also happen with
> >
> > kern.timecounter.hardware=acpihpet
> >
> > ?
>
> Ran the code with kern.timecounter.hardware=acpihpet0 for 10 minutes
> without any output.
>
> With the code still running, I switched to tsc and starting seeing output:
>
> 151944.345840447 precedes 151944.647753895
> 151944.525774690 precedes 151944.827681380
> 151946.405553296 precedes 151946.707533012
>
> The output stops as soon as I switch back to acpihpet0.
>
> I will add that to my /etc/sysctl.conf.
>
> Thank you.

So the TSCs on the cores of your brand new Intel Kaby Lake R processor
are out of sync.  That is the final drop.  I disabled the code that
promotes the TSC as a high-quality timecounter on MULTIPROCESSOR
kernels.  It simply doesn't work on a significant fraction of machines
and causes all kinds of weird problems.

Scott, any change to turn that bit of code into a regress test?