Date: Sun, 11 Feb 2024 08:26:21 +0000 From: bugzilla-noreply@freebsd.org To: bugs@FreeBSD.org Subject: [Bug 276967] sysctl dev.hwpstate_intel periodically slow Message-ID: <bug-276967-227@https.bugs.freebsd.org/bugzilla/>
next in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D276967 Bug ID: 276967 Summary: sysctl dev.hwpstate_intel periodically slow Product: Base System Version: 13.2-STABLE Hardware: Any OS: Any Status: New Severity: Affects Some People Priority: --- Component: kern Assignee: bugs@FreeBSD.org Reporter: thomas@gibfest.dk Hello, We have a server which has developed a periodic issue where the server beco= mes weirdly slow and unresponsive and only a hard reboot seems to help. It happ= ened again today and I tried digging into it a bit before rebooting. This has become an issue since we upgraded from 13-STABLE-93f39b4675 (built July 21st, 2023) to 13-STABLE-7a241fa318 (built on December 11th, 2023). Digging through commits to stable/13 in that period did not turn up anything that caught my eye. It turns out it is because monitoring is running /usr/sbin/prometheus_sysctl_exporter once every minute in a monitoring job. This is usually not an issue. Digging into it today it turns out it is sysc= tl itself that is being slow, when it has to print out the dev.hwpstate_intel.X.epp number. Sometimes it is fast, sometimes it takes 1= -10 seconds to return, and sometimes minutes. I timed a `sysctl -a` and it took 39 minutes to return, pausing before prin= ting each of the 6 dev.hwpstate_intel.X.epp oids my system has. Uptime was 39ish days when this happened, last time it happened uptime was = just over 3 weeks. While the issue was active this morning I tried running "truss sysctl dev.hwpstate_intel" and it doesn't show any difference between a "fast" run= and a "slow" run. It pauses after printing this line (the numbers vary but it is always at the oidfmt call) __sysctl("sysctl.oidfmt dev.hwpstate_intel.0.epp",6,0x3a7c02008450,0x3a7c020077d8,0x0,0) =3D 0 (0x0) The next call after the oidfmt call is: __sysctl("dev.hwpstate_intel.0.epp",4,0x0,0x3a7c020077d0,0x0,0) =3D 0 (0x0) So I guess this might be what is taking a long time? I've included /var/run/dmesg.boot in case it is relevant. The server is an Intel NUC: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D [tykling@nuc1 ~]$ cat /var/run/dmesg.boot=20 Copyright (c) 1992-2021 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. FreeBSD is a registered trademark of The FreeBSD Foundation. FreeBSD 13.2-STABLE stable/13-7a241fa318 GENERIC amd64 FreeBSD clang version 16.0.6 (https://github.com/llvm/llvm-project.git llvmorg-16.0.6-0-g7cbf1a259152) VT(vga): resolution 640x480 CPU: Intel(R) Core(TM) i7-10710U CPU @ 1.10GHz (1600.00-MHz K8-class CPU) Origin=3D"GenuineIntel" Id=3D0xa0660 Family=3D0x6 Model=3D0xa6 Steppi= ng=3D0 =20 Features=3D0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,= MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE> =20 Features2=3D0x7ffafbbf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,S= DBG,FMA,CX16,xTPR,PDCM,PCID,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,TSCDLT,AESNI,= XSAVE,OSXSAVE,AVX,F16C,RDRAND> AMD Features=3D0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM> AMD Features2=3D0x121<LAHF,ABM,Prefetch> Structured Extended Features=3D0x29c67af<FSGSBASE,TSCADJ,SGX,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,N= FPUSG,MPX,RDSEED,ADX,SMAP,CLFLUSHOPT,PROCTRACE> Structured Extended Features3=3D0xbc000400<MD_CLEAR,IBPB,STIBP,L1DFL,ARCH_CAP,SSBD> XSAVE Features=3D0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES> IA32_ARCH_CAPS=3D0x2b<RDCL_NO,IBRS_ALL,SKIP_L1DFL_VME,MDS_NO> VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID TSC: P-state invariant, performance statistics real memory =3D 34359738368 (32768 MB) avail memory =3D 33013563392 (31484 MB) Event timer "LAPIC" quality 600 ACPI APIC Table: <INTEL NUC9i5FN> FreeBSD/SMP: Multiprocessor System Detected: 6 CPUs FreeBSD/SMP: 1 package(s) x 6 core(s) random: registering fast source Intel Secure Key RNG random: fast provider: "Intel Secure Key RNG" random: unblocking device. ioapic0 <Version 2.0> irqs 0-119 Launching APs: 2 3 4 1 5 random: entropy device external interface kbd0 at kbdmux0 efirtc0: <EFI Realtime Clock> efirtc0: registered as a time-of-day clock, resolution 1.000000s smbios0: <System Management BIOS> at iomem 0x2f9df000-0x2f9df01e smbios0: Version: 3.3, BCD Revision: 3.3 aesni0: <AES-CBC,AES-CCM,AES-GCM,AES-ICM,AES-XTS> acpi0: <INTEL> acpi0: Power Button (fixed) cpu0: <ACPI CPU> on acpi0 hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 24000000 Hz quality 950 Event timer "HPET" frequency 24000000 Hz quality 550 Event timer "HPET1" frequency 24000000 Hz quality 440 Event timer "HPET2" frequency 24000000 Hz quality 440 attimer0: <AT timer> port 0x40-0x43,0x50-0x53 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0 acpi_ec0: <Embedded Controller: GPE 0x6e> port 0x62,0x66 on acpi0 pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0 pci0: <ACPI PCI bus> on pcib0 vgapci0: <VGA-compatible display> port 0x3000-0x303f mem 0x6000000000-0x6000ffffff,0x4000000000-0x400fffffff at device 2.0 on pci0 vgapci0: Boot video device xhci0: <XHCI (generic) USB 3.0 controller> mem 0x6001000000-0x600100ffff at device 20.0 on pci0 xhci0: 32 bytes context size, 64-bit DMA usbus0 on xhci0 usbus0: 5.0Gbps Super Speed USB v3.0 pci0: <memory, RAM> at device 20.2 (no driver attached) pci0: <serial bus> at device 21.0 (no driver attached) pci0: <serial bus> at device 21.2 (no driver attached) pci0: <simple comms> at device 22.0 (no driver attached) ahci0: <AHCI SATA controller> port 0x3090-0x3097,0x3080-0x3083,0x3060-0x307f mem 0x3d220000-0x3d221fff,0x3d223000-0x3d2230ff,0x3d222000-0x3d2227ff at de= vice 23.0 on pci0 ahci0: AHCI v1.31 with 1 6Gbps ports, Port Multiplier not supported ahcich2: <AHCI channel> at channel 2 on ahci0 pcib1: <ACPI PCI-PCI bridge> at device 29.0 on pci0 pci1: <ACPI PCI bus> on pcib1 nvme0: <Generic NVMe Device> mem 0x3d100000-0x3d103fff at device 0.0 on pci1 pcib2: <ACPI PCI-PCI bridge> at device 29.5 on pci0 pci2: <ACPI PCI bus> on pcib2 sdhci_pci0: <Generic SD HCI> mem 0x3d000000-0x3d000fff at device 0.0 on pci2 sdhci_pci0: 1 slot(s) allocated isab0: <PCI-ISA bridge> at device 31.0 on pci0 isa0: <ISA bus> on isab0 pci0: <serial bus> at device 31.5 (no driver attached) em0: <Intel(R) I219-V CMP(10)> mem 0x3d200000-0x3d21ffff at device 31.6 on = pci0 em0: EEPROM V0.8-4 em0: Using 1024 TX descriptors and 1024 RX descriptors em0: Using an MSI interrupt em0: Ethernet address: 1c:69:7a:ab:fe:be em0: netmap queues/slots: TX 1/1024, RX 1/1024 acpi_button0: <Sleep Button> on acpi0 acpi_button1: <Power Button> on acpi0 acpi_tz0: <Thermal Zone> on acpi0 acpi_syscontainer0: <System Container> on acpi0 acpi_tz1: <Thermal Zone> on acpi0 acpi_tz1: _HOT value is absurd, ignored (-73.1C) atrtc0: <AT realtime clock> at port 0x70 irq 8 on isa0 atrtc0: Warning: Couldn't map I/O. atrtc0: registered as a time-of-day clock, resolution 1.000000s Event timer "RTC" frequency 32768 Hz quality 0 atrtc0: non-PNP ISA device will be removed from GENERIC in FreeBSD 15. hwpstate_intel0: <Intel Speed Shift> on cpu0 hwpstate_intel1: <Intel Speed Shift> on cpu1 hwpstate_intel2: <Intel Speed Shift> on cpu2 hwpstate_intel3: <Intel Speed Shift> on cpu3 hwpstate_intel4: <Intel Speed Shift> on cpu4 hwpstate_intel5: <Intel Speed Shift> on cpu5 Timecounter "TSC" frequency 1607993387 Hz quality 1000 Timecounters tick every 1.000 msec ZFS filesystem version: 5 ZFS storage pool version: features support (5000) acpi_tz1: _TMP value is absurd, ignored (-263.1C) ugen0.1: <Intel XHCI root HUB> at usbus0 uhub0 on usbus0 uhub0: <Intel XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0 nvd0: <INTEL SSDPEKNW512G8> NVMe namespace nvd0: 488386MB (1000215216 512 byte sectors) ada0 at ahcich2 bus 0 scbus0 target 0 lun 0 ada0: <WDC WDS100T1R0A-68A4W0 411000WR> ACS-4 ATA SATA 3.x device ada0: Serial Number 21356C802096 ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 512bytes) ada0: Command Queueing enabled ada0: 953869MB (1953525168 512 byte sectors) Trying to mount root from zfs:zroot/ROOT/13-STABLE-7a241fa318 []... GEOM_MIRROR: Device mirror/swap launched (2/2). uhub0: 18 ports with 18 removable, self powered GEOM_ELI: Device mirror/swap.eli created. GEOM_ELI: Encryption: AES-XTS 128 GEOM_ELI: Crypto: accelerated software pchtherm0: <CometLake-LP Thermal Subsystem> mem 0x6001017000-0x6001017fff at device 18.0 on pci0 ig4iic0: <Intel Comet Lake-LP I2C Controller-0> at device 21.0 on pci0 ig4iic0: Using MSI iicbus0: <Philips I2C bus (ACPI-hinted)> on ig4iic0 ig4iic1: <Intel Comet Lake-LP I2C Controller-2> at device 21.2 on pci0 ig4iic1: Using MSI iicbus1: <Philips I2C bus (ACPI-hinted)> on ig4iic1 iicbus1: <unknown card> at addr 0x20 ichsmb0: <Intel Comet Lake SMBus controller> port 0xefa0-0xefbf mem 0x6001012000-0x60010120ff at device 31.4 on pci0 smbus0: <System Management Bus> on ichsmb0 acpi_wmi0: <ACPI-WMI mapping> on acpi0 acpi_wmi0: Embedded MOF found ACPI: \134AMW0.WQBA: 1 arguments were passed to a non-method ACPI object (Buffer) (20201113/nsarguments-361) acpi_wmi1: <ACPI-WMI mapping> on acpi0 acpi_wmi2: <ACPI-WMI mapping> on acpi0 acpi_wmi2: Embedded MOF found ACPI: \134_SB.WFDE.WQCC: 1 arguments were passed to a non-method ACPI object (Buffer) (20201113/nsarguments-361) acpi_wmi3: <ACPI-WMI mapping> on acpi0 acpi_wmi3: Embedded MOF found ACPI: \134_SB.WFTE.WQCC: 1 arguments were passed to a non-method ACPI object (Buffer) (20201113/nsarguments-361) bridge1: Ethernet address: 58:9c:fc:10:8e:78 bridge0: Ethernet address: 58:9c:fc:10:cc:5a lo0: link state changed to UP em0: link state changed to UP pflog0: promiscuous mode enabled Accounting enabled =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D powerd is not enabled on the system. It used to be, but it has been disable= d in December when I first discovered this issue. I hoped disabling powerd would make the issue go away but it hasn't. I realise this isn't a lot to go on, and I can't really force the issue, so= if anyone has any suggestions to what I might try the next time it happens then please share them. It might be weeks thought. The server is in production b= ut I can test stuff in off-hours. Thank you! :) --=20 You are receiving this mail because: You are the assignee for the bug.=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-276967-227>