Bug #3299
openDragonFlyBSD reports utterly wrong uptime (most of the time, right after booting in)
0%
Description
System environment:
root@dragonflybsd /home/adrian # uname -a DragonFly dragonflybsd.v-zone.lan.dac 6.0-RELEASE DragonFly v6.0.1-RELEASE #1: Thu Oct 14 18:25:27 CEST 2021 adrian@dragonflybsd.v-zone.lan.dac:/usr/obj/usr/src/sys/X86_64_GENERIC x86_64
Running DragonFlyBSD inside a Debian KVM virtualization as a guest with hardware acceleration,
the system reports a very wrong uptime, issuing "uptime".
Gkrellm even reports a negative, very strange uptime! Check by running gkrellm from the pkg system.
After ~2 days of uptime, I see this wrong uptime:
root@dragonflybsd /home/adrian # uptime 6:35PM up 42954 days, 10:01, 2 users, load averages: 0,00 0,00 0,00
The error also was present with Version 6.0.0. This is now Version 6.0.1 and the bug is still there.
Happens about three of four times, the bug is present right after booting into the system.
Thank you for taking the time reading this.
Sincerely,
Adrian Kieß
Updated by adrian about 3 years ago
Tuxillo @ the IRC channel asked for my KVM qemu libvirtd execution stanza.
It is automatically generated through using virt-manager on a Debian Linux host.
Here it is:
libvirt+ 3497 21.7 12.0 6130296 1977972 ? Sl oct.22 997:16 /usr/bin/qemu-system-x86_64 -name guest=dragonflybsd,debug-threads=on -S -object {"qom-type":"secret","id":"masterKey0","format":"raw","file":"/var/lib/libvirt/qemu/domain-1-dragonflybsd/master-key.aes"} -machine pc-i440fx-5.2,accel=kvm,usb=off,vmport=off,dump-guest-core=off,memory-backend=pc.ram -cpu Nehalem-IBRS,vme=on,vmx=on,pdcm=on,x2apic=on,tsc-deadline=on,hypervisor=on,arat=on,tsc-adjust=on,umip=on,stibp=on,arch-capabilities=on,ssbd=on,rdtscp=on,ibpb=on,ibrs=on,amd-stibp=on,amd-ssbd=on,skip-l1dfl-vmentry=on,pschange-mc-no=on -m 3584 -object {"qom-type":"memory-backend-ram","id":"pc.ram","size":3758096384} -overcommit mem-lock=off -smp 4,sockets=4,cores=1,threads=1 -uuid 7b285e22-0468-4de3-834a-ee170e65b44b -no-user-config -nodefaults -chardev socket,id=charmonitor,fd=31,server=on,wait=off -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -global kvm-pit.lost_tick_policy=delay -no-hpet -no-shutdown -global PIIX4_PM.disable_s3=1 -global PIIX4_PM.disable_s4=1 -boot strict=on -device ich9-usb-ehci1,id=usb,bus=pci.0,addr=0x5.0x7 -device ich9-usb-uhci1,masterbus=usb.0,firstport=0,bus=pci.0,multifunction=on,addr=0x5 -device ich9-usb-uhci2,masterbus=usb.0,firstport=2,bus=pci.0,addr=0x5.0x1 -device ich9-usb-uhci3,masterbus=usb.0,firstport=4,bus=pci.0,addr=0x5.0x2 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x6 -device ide-cd,bus=ide.0,unit=1,id=ide0-0-1 -blockdev {"driver":"file","filename":"/client/libvirt/images/dragonflybsd.qcow2","node-name":"libvirt-1-storage","auto-read-only":true,"discard":"unmap"} -blockdev {"node-name":"libvirt-1-format","read-only":false,"driver":"qcow2","file":"libvirt-1-storage","backing":null} -device virtio-blk-pci,bus=pci.0,addr=0x8,drive=libvirt-1-format,id=virtio-disk0,bootindex=1 -netdev tap,fd=33,id=hostnet0,vhost=on,vhostfd=34 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:c2:24:94,bus=pci.0,addr=0x3 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -audiodev id=audio1,driver=spice -spice port=5900,addr=127.0.0.1,disable-ticketing=on,image-compression=off,seamless-migration=on -device qxl-vga,id=video0,ram_size=67108864,vram_size=67108864,vram64_size_mb=0,vgamem_mb=16,max_outputs=1,bus=pci.0,addr=0x2 -device intel-hda,id=sound0,bus=pci.0,addr=0x4 -device hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0,audiodev=audio1 -chardev spicevmc,id=charredir0,name=usbredir -device usb-redir,chardev=charredir0,id=redir0,bus=usb.0,port=1 -chardev spicevmc,id=charredir1,name=usbredir -device usb-redir,chardev=charredir1,id=redir1,bus=usb.0,port=2 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7 -sandbox on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny -msg timestamp=on
Sincerely,
Adrian Kieß
Updated by tuxillo about 3 years ago
- Description updated (diff)
- Category set to Userland
- Status changed from New to In Progress
- Target version changed from 6.0 to 6.2
Updated by tuxillo about 3 years ago
Can you please try activating dntpd? Does it make a difference?
Updated by adrian about 3 years ago
tuxillo wrote in #note-5:
Can you please try activating dntpd? Does it make a difference?
I had DNTPD already enabled.
Setting dntpd_enable= "NO" in /etc/rc.conf fixes the issue!
Thank you for the hint!
Sincerely,
Adrian
Updated by adrian about 3 years ago
tuxillo wrote in #note-5:
Can you please try activating dntpd? Does it make a difference?
Hello tuxillo. Disabling DNTPD does NOT fix issue.
The problem reapeared after rebooting my DragonFlyBSD virtual machine three times.
Sincerely,
Adrian
Updated by daftaupe almost 2 years ago
I could reproduce on a KVM vm of mine after a random reboot
% uname -v
DragonFly v6.5.0.2.g030731-DEVELOPMENT #1: Thu Jan 5 22:36:59 CET 2023 root@dfly:/usr/obj/usr/src/sys/X86_64_GENERIC
% uptime
11:41AM up 42951 days, 6:22, 2 users, load averages: 0.00, 0.00, 0.00
% top
load averages: 0.05, 0.01, 0.00; up 42951+06:24:24 11:42:32
I will try to keep it on for some time see if that resolves by itself after some time, but time is already synchronized and accurate
Jan 7 10:30:29 dfly dntpd[575]: 1.dragonfly.pool.ntp.org (51.178.79.86): DNS lookup success
Jan 7 10:30:29 dfly dntpd[575]: 2.dragonfly.pool.ntp.org (212.83.158.83): DNS lookup success
Jan 7 10:30:29 dfly dntpd[575]: 3.dragonfly.pool.ntp.org (193.52.136.2): DNS lookup success
Jan 7 10:30:34 dfly dntpd[575]: 0.dragonfly.pool.ntp.org (193.52.136.2): DNS lookup success
Jan 7 10:30:34 dfly dntpd[575]: 1.dragonfly.pool.ntp.org (51.178.79.86): connected ok
Jan 7 10:30:34 dfly dntpd[575]: 2.dragonfly.pool.ntp.org (212.83.158.83): connected ok
Jan 7 10:30:34 dfly dntpd[575]: 3.dragonfly.pool.ntp.org (193.52.136.2): connected ok
Jan 7 10:30:34 dfly dntpd[575]: 0.dragonfly.pool.ntp.org: permanently disabling duplicate server
Jan 7 11:30:51 dfly dntpd[575]: issuing COARSE offset adjustment: 3600.857181s, 07-Jan-2023 11:30:51.946
Here is the full dmesg output
% dmesg
Copyright (c) 2003-2023 The DragonFly Project.
Copyright (c) 1992-2003 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
DragonFly v6.5.0.2.g030731-DEVELOPMENT #1: Thu Jan 5 22:36:59 CET 2023
root@dfly:/usr/obj/usr/src/sys/X86_64_GENERIC
Using cputimer i8254_timer2 for TSC calibration
Timer latency (in TSC ticks): 17024 min=8225 max=17605
TSC clock: 3496299680 Hz
CPU: AMD Ryzen 3 2200G with Radeon Vega Graphics (3496.30-MHz K8-class CPU)
Origin = "AuthenticAMD" Id = 0x810f10 Stepping = 0
Features=0x783fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2>
Features2=0xf7f83203<SSE3,PCLMULQDQ,SSSE3,FMA,CX16,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,TSCDLT,AESNI,XSAVE,AVX,F16C,RDRN>
IA32_ARCH_CAPS=0x69<RDCL_NO,SKIP_L1DFL_VME,MDS_NO>
AMD Features=0x2e500800<SYSCALL,NX,MMX+,FFXSR,Page1GB,RDTSCP,LM>
AMD Features2=0x8003f7<LAHF,CMP,SVM,CR8,ABM,SSE4A,MAS,Prefetch,OSVW,PCX_CORE>
Structured Extended Features=0x209c012a<TSCADJ,BMI1,AVX2,BMI2,RDSEED,ADX,SMAP,CLFLUSHOPT,SHA>
Structured Extended Features3=0x20000000<ARCH_CAP>
Thermal and PM Features=0x4<ARAT>
MONITOR/MWAIT Features=0x2<INTBRK>
CPU Special Features Installed: SMAP
real memory = 4290813952 (4092 MB)
avail memory = 4086304768 (3897 MB)
LAPIC: enter X2APIC mode
madt_lapic_probe: lapic_count=3 x2apic_count=0
ACPI CPUS = 3
lapic: divisor index 0, frequency 500001558 Hz
CPU Topology: cores_per_chip: 1; threads_per_core: 1; chips_per_package: 3;
srat_probe: can't locate SRAT
SMI Frequency (worst case): 4065 Hz (246 us)
Initialize MI interrupts for 3 cpus
TSC is not invariant, no further tests will be performed
Spectre: support=( IBPB ) req=0000 operating=( none )
MDS: support=( MDS_NOT_REQUIRED ) req=0000 operating=( none )
interrupt uses mplock: swi_taskq
wdog: In-kernel automatic watchdog reset enabled
md0: Malloc disk
evdev device loaded.
kbd1 at kbdmux0
ACPI: RSDP 0x00000000BFB7E014 000024 (v02 BOCHS )
ACPI: XSDT 0x00000000BFB7D0E8 000044 (v01 BOCHS BXPC 00000001 01000013)
ACPI: FACP 0x00000000BFB7A000 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
ACPI: DSDT 0x00000000BFB7B000 001890 (v01 BOCHS BXPC 00000001 BXPC 00000001)
ACPI: FACS 0x00000000BFBDD000 000040
ACPI: APIC 0x00000000BFB79000 000088 (v01 BOCHS BXPC 00000001 BXPC 00000001)
ACPI: WAET 0x00000000BFB78000 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
ACPI: BGRT 0x00000000BFB77000 000038 (v01 INTEL EDK2 00000002 01000013)
sc0: <System console> on motherboard
sc0: EFI_FB <16 virtual consoles, flags=0x700>
cryptosoft0: <software crypto> on motherboard
acpi0: <BOCHS BXPC> on motherboard
ACPI: 1 ACPI AML tables successfully acquired and loaded
ACPI FADT: SCI testing interrupt mode ...
ACPI FADT: SCI select level/high
acpi0: Power Button (fixed)
acpi_timer0 on acpi0
isab0: <ACPI Generic ISA bridge> on acpi0
isa0: <ISA bus> on isab0
cpu0: <ACPI CPU> on acpi0
Warning: hardclock missed > 1 sec
cpu_cst0: <ACPI CPU C-State> on cpu0
cpu1: <ACPI CPU> on acpi0
cpu_cst1: <ACPI CPU C-State> on cpu1
cpu2: <ACPI CPU> on acpi0
cpu_cst2: <ACPI CPU C-State> on cpu2
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci_link4: BIOS IRQ 10 for 0.1.INTA is invalid
pci0: <ACPI PCI bus> on pcib0
isab1: <PCI-ISA bridge> at device 1.0 on pci0
isa1: <ISA bus> on isab1
atapci0: <Intel PIIX3 WDMA2 controller> port 0xc1a0-0xc1af,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 1.1 on pci0
ata0: <ATA channel 0> on atapci0
interrupt uses mplock: ata0
ata1: <ATA channel 1> on atapci0
interrupt uses mplock: ata1
pci0: <bridge> (vendor 0x8086, dev 0x7113) at device 1.3 irq 9
vgapci0: <VGA-compatible display> port 0xc180-0xc19f mem 0xc8044000-0xc8045fff,0xc0000000-0xc3ffffff,0xc4000000-0xc7fff0
vgapci0: Boot video device
virtio_pci0: <VirtIO PCI Network adapter> port 0xc160-0xc17f mem 0x700000000000-0x700000003fff,0xc8049000-0xc8049fff ir0
vtnet0: <VirtIO Networking Adapter> on virtio_pci0
virtio_pci0: host features: 0x79bfffe7 <EventIdx,RingIndirect,AnyLayout,NotifyOnEmpty,SetMacAddress,GuestAnnounce,RxMod>
virtio_pci0: negotiated features: 0x198f83a1 <RingIndirect,AnyLayout,NotifyOnEmpty,SetMacAddress,VLanFilter,RxMode,Cont>
virtio_pci0: using 3 MSI-X vectors
vtnet0: MAC address: 52:54:00:7e:af:b8
pci0: <multimedia, HDA> (vendor 0x8086, dev 0x2668) at device 4.0 irq 11
uhci0: <Intel 82801I (ICH9) USB controller> port 0xc140-0xc15f irq 10 at device 5.0 on pci0
usbus0 on uhci0
usbus0: 12Mbps Full Speed USB v1.0
ugen0.1: <Intel> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
usbus1 on uhci1
usbus1: 12Mbps Full Speed USB v1.0
uhci2: <Intel 82801I (ICH9) USB controller> port 0xc100-0xc11f irq 11 at device 5.2 on pci0
ugen1.1: <Intel> at usbus1
uhub1: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
usbus2 on uhci2
usbus2: 12Mbps Full Speed USB v1.0
usbus3: EHCI version 1.0
ugen2.1: <Intel> at usbus2
uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
usbus3 on ehci0
usbus3: 480Mbps High Speed USB v2.0
virtio_pci2: <VirtIO PCI Block adapter> port 0xc000-0xc07f mem 0x700000008000-0x70000000bfff,0xc8046000-0xc8046fff irq 0
ugen3.1: <Intel> at usbus3
uhub3: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus3
uhub0: 2 ports with 2 removable, self powered
vtblk0: Block size: 512
vtblk0: 10240MB (20971520 512 byte sectors: 16H 63S/T 16383C)
virtio_pci3: <VirtIO PCI Balloon adapter> port 0xc080-0xc0bf mem 0x70000000c000-0x70000000ffff irq 11 at device 8.0 on 0
vtballoon0: <VirtIO Balloon Adapter> on virtio_pci3
virtio_pci3: host features: 0x79000012 <EventIdx,RingIndirect,AnyLayout,NotifyOnEmpty,0x10,StatsVq>
virtio_pci3: negotiated features: 0x2 <StatsVq>
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 on acpi0
sio0: type 16550A
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
uhub2: 2 ports with 2 removable, self powered
uhub1: 2 ports with 2 removable, self powered
psm0: <PS/2 Mouse> irq 12 on atkbdc0
interrupt uses mplock: psm0
psm0: model IntelliMouse Explorer, device ID 4
ACPI: Enabled 2 GPEs in block 00 to 0F
aesni0: <AES-CBC,AES-XTS> on motherboard
padlock0: No ACE support.
rdrand0: <RdRand RNG> on motherboard
sio2: can't drain, serial port might not exist, disabling
hpt27xx: no controller detected.
CAM: Configuring 2 busses
CAM: finished configuring all busses
uhub3: 6 ports with 6 removable, self powered
ugen3.2: <QEMU> at usbus3
uhid0: <QEMU QEMU USB Tablet, class 0/0, rev 2.00/0.00, addr 2> on usbus3
Mounting root from hammer2:vbd0s1d
hammer2_mount: root devstr="vbd0s1d"
hammer2_mount: device="vbd0s1d" label="ROOT" rdonly=1
hammer2_ondisk: "/dev/vbd0s1d" zone=1 id=0 offset=0x0000000000000000 size=0x00000001f7800000
hammer2_mount: hmp=0xfffff8008f640000 pmp=0xfffff8008dc98e00
DMA space used: 10052k, remaining available: 131072k
Mounting devfs
hammer2_mount: "vbd0s1d": no recovery needed
hammer2: enable read/write
reconnect to cluster: nc=1 focus=0
not a local device mount
swap low/high-water marks set to 10472/15709
And the full qemu command line
/usr/bin/qemu-system-x86_64 -name guest=dragonfly2,debug-threads=on -S -object {"qom-type":"secret","id":"masterKey0","format":"raw","file":"/var/lib/libvirt/qemu/domain-2-dragonfly2/master-key.aes"} -blockdev {"driver":"file","filename":"/usr/share/edk2/x64/OVMF_CODE.4m.fd","node-name":"libvirt-pflash0-storage","auto-read-only":true,"discard":"unmap"} -blockdev {"node-name":"libvirt-pflash0-format","read-only":true,"driver":"raw","file":"libvirt-pflash0-storage"} -blockdev {"driver":"file","filename":"/var/lib/libvirt/qemu/nvram/dragonfly2_VARS.fd","node-name":"libvirt-pflash1-storage","auto-read-only":true,"discard":"unmap"} -blockdev {"node-name":"libvirt-pflash1-format","read-only":false,"driver":"raw","file":"libvirt-pflash1-storage"} -machine pc-i440fx-7.2,usb=off,vmport=off,dump-guest-core=off,memory-backend=pc.ram,pflash0=libvirt-pflash0-format,pflash1=libvirt-pflash1-format -accel kvm -cpu host,migratable=on -m 4096 -object {"qom-type":"memory-backend-ram","id":"pc.ram","size":4294967296} -overcommit mem-lock=off -smp 3,sockets=3,cores=1,threads=1 -uuid 1ff97937-812f-4ced-8d88-e540acd06a33 -no-user-config -nodefaults -chardev socket,id=charmonitor,fd=31,server=on,wait=off -mon chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew -global kvm-pit.lost_tick_policy=delay -no-hpet -no-shutdown -global PIIX4_PM.disable_s3=1 -global PIIX4_PM.disable_s4=1 -boot strict=on -device {"driver":"ich9-usb-ehci1","id":"usb","bus":"pci.0","addr":"0x5.0x7"} -device {"driver":"ich9-usb-uhci1","masterbus":"usb.0","firstport":0,"bus":"pci.0","multifunction":true,"addr":"0x5"} -device {"driver":"ich9-usb-uhci2","masterbus":"usb.0","firstport":2,"bus":"pci.0","addr":"0x5.0x1"} -device {"driver":"ich9-usb-uhci3","masterbus":"usb.0","firstport":4,"bus":"pci.0","addr":"0x5.0x2"} -device {"driver":"virtio-serial-pci","id":"virtio-serial0","bus":"pci.0","addr":"0x6"} -blockdev {"driver":"file","filename":"/var/lib/libvirt/images/dragonfly2.qcow2","node-name":"libvirt-1-storage","auto-read-only":true,"discard":"unmap"} -blockdev {"node-name":"libvirt-1-format","read-only":false,"driver":"qcow2","file":"libvirt-1-storage","backing":null} -device {"driver":"virtio-blk-pci","bus":"pci.0","addr":"0x7","drive":"libvirt-1-format","id":"virtio-disk0","bootindex":1} -netdev {"type":"tap","fd":"32","vhost":true,"vhostfd":"34","id":"hostnet0"} -device {"driver":"virtio-net-pci","netdev":"hostnet0","id":"net0","mac":"52:54:00:7e:af:b8","bus":"pci.0","addr":"0x3"} -chardev pty,id=charserial0 -device {"driver":"isa-serial","chardev":"charserial0","id":"serial0","index":0} -chardev spicevmc,id=charchannel0,name=vdagent -device {"driver":"virtserialport","bus":"virtio-serial0.0","nr":1,"chardev":"charchannel0","id":"channel0","name":"com.redhat.spice.0"} -device {"driver":"usb-tablet","id":"input0","bus":"usb.0","port":"1"} -audiodev {"id":"audio1","driver":"spice"} -spice port=5900,addr=127.0.0.1,disable-ticketing=on,image-compression=off,seamless-migration=on -device {"driver":"qxl-vga","id":"video0","max_outputs":1,"ram_size":67108864,"vram_size":67108864,"vram64_size_mb":0,"vgamem_mb":16,"bus":"pci.0","addr":"0x2"} -device {"driver":"intel-hda","id":"sound0","bus":"pci.0","addr":"0x4"} -device {"driver":"hda-duplex","id":"sound0-codec0","bus":"sound0.0","cad":0,"audiodev":"audio1"} -chardev spicevmc,id=charredir0,name=usbredir -device {"driver":"usb-redir","chardev":"charredir0","id":"redir0","bus":"usb.0","port":"2"} -chardev spicevmc,id=charredir1,name=usbredir -device {"driver":"usb-redir","chardev":"charredir1","id":"redir1","bus":"usb.0","port":"3"} -device {"driver":"virtio-balloon-pci","id":"balloon0","bus":"pci.0","addr":"0x8"} -sandbox on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny -msg timestamp=on
It's running on Linux 6.1.3 with qemu 7.2.0
Updated by adrian over 1 year ago
daftaupe wrote in #note-8:
I could reproduce on a KVM vm of mine after a random reboot
[...]
I will try to keep it on for some time see if that resolves by itself after some time, but time is already synchronized and accurate
[...]Here is the full dmesg output
[...]And the full qemu command line
[...]It's running on Linux 6.1.3 with qemu 7.2.0
Hello, as I am here right now, I just want to tell the above bug is still in DragonFlyBSD version 6.4. Thank you for reading this!