From owner-freebsd-stable@freebsd.org Sun Dec 31 14:17:11 2017 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id DCD68EB6E65 for ; Sun, 31 Dec 2017 14:17:11 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from mail.in-addr.com (mail.in-addr.com [IPv6:2a01:4f8:191:61e8::2525:2525]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id A9BAA744DB; Sun, 31 Dec 2017 14:17:11 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from gjp by mail.in-addr.com with local (Exim 4.90 (FreeBSD)) (envelope-from ) id 1eVeQG-000GIo-RE; Sun, 31 Dec 2017 14:17:08 +0000 Date: Sun, 31 Dec 2017 14:17:08 +0000 From: Gary Palmer To: freebsd-stable@freebsd.org Subject: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20171231141708.GA2629@in-addr.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline X-SA-Exim-Connect-IP: X-SA-Exim-Mail-From: gpalmer@freebsd.org X-SA-Exim-Scanned: No (on mail.in-addr.com); SAEximRunCond expanded to false X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 31 Dec 2017 14:17:12 -0000 Hi, I recently updated to 11.1-RELEASE-p6 and on the most recent reboot (after rebuilding all the necessary packages) the clock was running slow and NTP wouldn't sync. I looked in /var/log/messages and I found that for some reason, on this latest boot, it got the frequency of TSC-low wrong. Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 Hz quality 1000 Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 Hz quality 1000 Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 Hz quality 1000 Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 Hz quality 1000 Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 Hz quality 1000 Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 Hz quality 1000 Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 Hz quality 1000 Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 Hz quality 1000 Until the December reboots the machine was running 10.x. Dec 27 and later are part of the process to get up to 11.x. Any idea why the TSC-low frequency jumped 191,806,744Hz on the last measurement? I switched to HPET temporarily via sysctl and ntp seems happy. I'm just concerned that the problem might recur on later reboots as TSC-low seems to be the preferred timecounter. Thanks, Gary From owner-freebsd-stable@freebsd.org Sun Dec 31 14:51:55 2017 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id C7882EB8332 for ; Sun, 31 Dec 2017 14:51:55 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4664075B95; Sun, 31 Dec 2017 14:51:55 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from tom.home (kib@localhost [127.0.0.1]) by kib.kiev.ua (8.15.2/8.15.2) with ESMTPS id vBVEplLu077057 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Sun, 31 Dec 2017 16:51:50 +0200 (EET) (envelope-from kostikbel@gmail.com) DKIM-Filter: OpenDKIM Filter v2.10.3 kib.kiev.ua vBVEplLu077057 Received: (from kostik@localhost) by tom.home (8.15.2/8.15.2/Submit) id vBVEplbv077056; Sun, 31 Dec 2017 16:51:47 +0200 (EET) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com using -f Date: Sun, 31 Dec 2017 16:51:47 +0200 From: Konstantin Belousov To: Gary Palmer Cc: freebsd-stable@freebsd.org Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20171231145147.GW1684@kib.kiev.ua> References: <20171231141708.GA2629@in-addr.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20171231141708.GA2629@in-addr.com> User-Agent: Mutt/1.9.2 (2017-12-15) X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no autolearn_force=no version=3.4.1 X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on tom.home X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 31 Dec 2017 14:51:55 -0000 On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > Hi, > > I recently updated to 11.1-RELEASE-p6 and on the most recent reboot > (after rebuilding all the necessary packages) the clock was running > slow and NTP wouldn't sync. I looked in /var/log/messages and I found > that for some reason, on this latest boot, it got the frequency of > TSC-low wrong. > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 Hz quality 1000 > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 Hz quality 1000 > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 Hz quality 1000 > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 Hz quality 1000 > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 Hz quality 1000 > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 Hz quality 1000 > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 Hz quality 1000 > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 Hz quality 1000 > > Until the December reboots the machine was running 10.x. Dec 27 and later > are part of the process to get up to 11.x. > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the last > measurement? > > I switched to HPET temporarily via sysctl and ntp seems happy. I'm just > concerned that the problem might recur on later reboots as TSC-low seems > to be the preferred timecounter. Show first 100 lines of the dmesg from a verbose boot. Also check BIOS settings related to overclocking and powersaving. From owner-freebsd-stable@freebsd.org Sun Dec 31 15:49:15 2017 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 867FAE814BD for ; Sun, 31 Dec 2017 15:49:15 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from mail.in-addr.com (mail.in-addr.com [IPv6:2a01:4f8:191:61e8::2525:2525]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 0C41B773BB for ; Sun, 31 Dec 2017 15:49:15 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from gjp by mail.in-addr.com with local (Exim 4.90 (FreeBSD)) (envelope-from ) id 1eVfrN-000GTu-40; Sun, 31 Dec 2017 15:49:13 +0000 Date: Sun, 31 Dec 2017 15:49:13 +0000 From: Gary Palmer To: Konstantin Belousov Cc: freebsd-stable@freebsd.org Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20171231154913.GA63310@in-addr.com> References: <20171231141708.GA2629@in-addr.com> <20171231145147.GW1684@kib.kiev.ua> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="pf9I7BMVVzbSWLtt" Content-Disposition: inline In-Reply-To: <20171231145147.GW1684@kib.kiev.ua> X-SA-Exim-Connect-IP: X-SA-Exim-Mail-From: gpalmer@freebsd.org X-SA-Exim-Scanned: No (on mail.in-addr.com); SAEximRunCond expanded to false X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 31 Dec 2017 15:49:15 -0000 --pf9I7BMVVzbSWLtt Content-Type: text/plain; charset=us-ascii Content-Disposition: inline On Sun, Dec 31, 2017 at 04:51:47PM +0200, Konstantin Belousov wrote: > On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > > > Hi, > > > > I recently updated to 11.1-RELEASE-p6 and on the most recent reboot > > (after rebuilding all the necessary packages) the clock was running > > slow and NTP wouldn't sync. I looked in /var/log/messages and I found > > that for some reason, on this latest boot, it got the frequency of > > TSC-low wrong. > > > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 Hz quality 1000 > > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 Hz quality 1000 > > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 Hz quality 1000 > > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 Hz quality 1000 > > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 Hz quality 1000 > > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 Hz quality 1000 > > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 Hz quality 1000 > > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 Hz quality 1000 > > > > Until the December reboots the machine was running 10.x. Dec 27 and later > > are part of the process to get up to 11.x. > > > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the last > > measurement? > > > > I switched to HPET temporarily via sysctl and ntp seems happy. I'm just > > concerned that the problem might recur on later reboots as TSC-low seems > > to be the preferred timecounter. > > Show first 100 lines of the dmesg from a verbose boot. > Also check BIOS settings related to overclocking and powersaving. > Hi Konstantin, BIOS settings haven't been changed in 4+ years. No overclocking, and all powersaving options are at "auto" or "disabled". The first 100 lines of verbose dmesg didn't seem that interesting so I've included up to the end of "Device configuration finished" Note that this boot didn't have the TSC-low problem, and the boot that had it wasn't verbose unfortunately. Thanks, Gary --pf9I7BMVVzbSWLtt Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename="my-dmesg.boot" Table 'FACP' at 0xddc1a6b0 Table 'APIC' at 0xddc1a7c0 APIC: Found table at 0xddc1a7c0 APIC: Using the MADT enumerator. MADT: Found CPU APIC ID 0 ACPI ID 1: enabled SMP: Added CPU 0 (AP) MADT: Found CPU APIC ID 2 ACPI ID 2: enabled SMP: Added CPU 2 (AP) MADT: Found CPU APIC ID 4 ACPI ID 3: enabled SMP: Added CPU 4 (AP) MADT: Found CPU APIC ID 6 ACPI ID 4: enabled SMP: Added CPU 6 (AP) MADT: Found CPU APIC ID 1 ACPI ID 5: enabled SMP: Added CPU 1 (AP) MADT: Found CPU APIC ID 3 ACPI ID 6: enabled SMP: Added CPU 3 (AP) MADT: Found CPU APIC ID 5 ACPI ID 7: enabled SMP: Added CPU 5 (AP) MADT: Found CPU APIC ID 7 ACPI ID 8: enabled SMP: Added CPU 7 (AP) Copyright (c) 1992-2017 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 11.1-RELEASE-p6 #42 r327238: Wed Dec 27 17:55:36 GMT 2017 root@my:/usr/obj/usr/src/sys/MY amd64 FreeBSD clang version 4.0.0 (tags/RELEASE_400/final 297347) (based on LLVM 4.0.0) Table 'FACP' at 0xddc1a6b0 Table 'APIC' at 0xddc1a7c0 Table 'FPDT' at 0xddc1a858 Table 'MCFG' at 0xddc1a8a0 Table 'HPET' at 0xddc1a8e0 Table 'SSDT' at 0xddc1a918 Table 'DMAR' at 0xddc1c128 Table 'SSDT' at 0xddc1ace0 Table 'SSDT' at 0xddc1b690 ACPI: No SRAT table found PPIM 0: PA=0xb8000, VA=0xffffffff82a10000, size=0x8000, mode=0 VT(vga): text 80x25 Preloaded elf kernel "/boot/kernel/kernel" at 0xffffffff8287f000. Preloaded /boot/entropy "/boot/entropy" at 0xffffffff8287fc48. Preloaded elf obj module "/boot/kernel/zfs.ko" at 0xffffffff8287fc98. Preloaded elf obj module "/boot/kernel/opensolaris.ko" at 0xffffffff82880500. Preloaded elf obj module "/boot/kernel/geom_mirror.ko" at 0xffffffff82880b30. Preloaded elf obj module "/boot/modules/nvidia-modeset.ko" at 0xffffffff82881220. Preloaded elf obj module "/boot/kernel/linux.ko" at 0xffffffff828817d0. Preloaded elf obj module "/boot/kernel/linux_common.ko" at 0xffffffff828820b8. Preloaded elf obj module "/boot/modules/nvidia.ko" at 0xffffffff828827e8. Calibrating TSC clock ... TSC clock: 3492136124 Hz CPU: Intel(R) Xeon(R) CPU E3-1270 V2 @ 3.50GHz (3492.14-MHz K8-class CPU) Origin="GenuineIntel" Id=0x306a9 Family=0x6 Model=0x3a Stepping=9 Features=0xbfebfbff Features2=0x7fbae3ff AMD Features=0x28100800 AMD Features2=0x1 Structured Extended Features=0x281 XSAVE Features=0x1 VT-x: Basic Features=0xda0400 Pin-Based Controls=0x7f Primary Processor Controls=0xfff9fffe Secondary Processor Controls=0x8ff Exit Controls=0xda0400 Entry Controls=0xda0400 EPT Features=0x6114141 VPID Features=0xf01 TSC: P-state invariant, performance statistics Data TLB0: 2-MByte or 4 MByte pages, 4-way set associative, 32 entries Data TLB: 4 KB pages, 4-way set associative, 64 entries Instruction TLB: 2M/4M pages, fully associative, 8 entries Instruction TLB: 4KByte pages, 4-way set associative, 64 entries 64-Byte prefetching Shared 2nd-Level TLB: 4 KByte pages, 4-way associative, 512 entries L2 cache: 256 kbytes, 8-way associative, 64 bytes/line real memory = 34359738368 (32768 MB) Physical memory chunk(s): 0x0000000000010000 - 0x0000000000099fff, 565248 bytes (138 pages) 0x0000000000100000 - 0x00000000001fffff, 1048576 bytes (256 pages) 0x00000000028e7000 - 0x00000000dda0afff, 3675406336 bytes (897316 pages) 0x00000000de808000 - 0x00000000de808fff, 4096 bytes (1 pages) 0x00000000de84c000 - 0x00000000dec73fff, 4358144 bytes (1064 pages) 0x00000000deff4000 - 0x00000000deffffff, 49152 bytes (12 pages) 0x0000000100000000 - 0x00000007eb502fff, 29717704704 bytes (7255299 pages) avail memory = 33261993984 (31721 MB) Table 'FACP' at 0xddc1a6b0 Table 'APIC' at 0xddc1a7c0 Table 'FPDT' at 0xddc1a858 Table 'MCFG' at 0xddc1a8a0 Table 'HPET' at 0xddc1a8e0 Table 'SSDT' at 0xddc1a918 Table 'DMAR' at 0xddc1c128 DMAR: Found table at 0xddc1c128 Event timer "LAPIC" quality 600 ACPI APIC Table: Package ID shift: 4 L3 cache ID shift: 4 L2 cache ID shift: 1 L1 cache ID shift: 1 Core ID shift: 1 INTR: Adding local APIC 2 as a target INTR: Adding local APIC 4 as a target INTR: Adding local APIC 6 as a target FreeBSD/SMP: Multiprocessor System Detected: 8 CPUs FreeBSD/SMP: 1 package(s) x 4 core(s) x 2 hardware threads Package HW ID = 0 (0) Core HW ID = 0 (0) CPU0 (BSP): APIC ID: 0 (0) CPU1 (AP/HT): APIC ID: 1 (0x1) Core HW ID = 1 (0x1) CPU2 (AP): APIC ID: 2 (0x2) CPU3 (AP/HT): APIC ID: 3 (0x3) Core HW ID = 2 (0x2) CPU4 (AP): APIC ID: 4 (0x4) CPU5 (AP/HT): APIC ID: 5 (0x5) Core HW ID = 3 (0x3) CPU6 (AP): APIC ID: 6 (0x6) CPU7 (AP/HT): APIC ID: 7 (0x7) APIC: CPU 0 has ACPI ID 1 APIC: CPU 1 has ACPI ID 5 APIC: CPU 2 has ACPI ID 2 APIC: CPU 3 has ACPI ID 6 APIC: CPU 4 has ACPI ID 3 APIC: CPU 5 has ACPI ID 7 APIC: CPU 6 has ACPI ID 4 APIC: CPU 7 has ACPI ID 8 lapic0: CMCI unmasked Pentium Pro MTRR support enabled x86bios: IVT 0x000000-0x0004ff at 0xfffff80000000000 x86bios: SSEG 0x098000-0x098fff at 0xfffffe083c163000 x86bios: EBDA 0x09d000-0x09ffff at 0xfffff8000009d000 x86bios: ROM 0x0a0000-0x0fefff at 0xfffff800000a0000 random: read 4096 bytes from preloaded cache random: unblocking device. ULE: setup cpu 0 ULE: setup cpu 1 ULE: setup cpu 2 ULE: setup cpu 3 ULE: setup cpu 4 ULE: setup cpu 5 ULE: setup cpu 6 ULE: setup cpu 7 ACPI: RSDP 0x00000000000F0490 000024 (v02 ALASKA) ACPI: XSDT 0x00000000DDC0F078 00006C (v01 ALASKA A M I 01072009 AMI 00010013) ACPI: FACP 0x00000000DDC1A6B0 00010C (v05 ALASKA A M I 01072009 AMI 00010013) ACPI: DSDT 0x00000000DDC0F180 00B529 (v02 ALASKA A M I 00000022 INTL 20051117) ACPI: FACS 0x00000000DDD42080 000040 ACPI: APIC 0x00000000DDC1A7C0 000092 (v03 ALASKA A M I 01072009 AMI 00010013) ACPI: FPDT 0x00000000DDC1A858 000044 (v01 ALASKA A M I 01072009 AMI 00010013) ACPI: MCFG 0x00000000DDC1A8A0 00003C (v01 ALASKA A M I 01072009 MSFT 00000097) ACPI: HPET 0x00000000DDC1A8E0 000038 (v01 ALASKA A M I 01072009 AMI. 00000005) ACPI: SSDT 0x00000000DDC1A918 00036D (v01 SataRe SataTabl 00001000 INTL 20091112) ACPI: DMAR 0x00000000DDC1C128 000080 (v01 INTEL SNB 00000001 INTL 00000001) ACPI: SSDT 0x00000000DDC1ACE0 0009AA (v01 PmRef Cpu0Ist 00003000 INTL 20051117) ACPI: SSDT 0x00000000DDC1B690 000A92 (v01 PmRef CpuPm 00003000 INTL 20051117) MADT: Found IO APIC ID 2, Interrupt 0 at 0xfec00000 ioapic0: ver 0x20 maxredir 0x17 ioapic0: Routing external 8259A's -> intpin 0 MADT: Interrupt override: source 0, irq 2 ioapic0: Routing IRQ 0 -> intpin 2 MADT: Interrupt override: source 9, irq 9 ioapic0: intpin 9 trigger: level lapic: Routing NMI -> LINT1 lapic: LINT1 trigger: edge lapic: LINT1 polarity: high ioapic0 irqs 0-23 on motherboard cpu0 BSP: ID: 0x00000000 VER: 0x01060015 LDR: 0x00000001 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 lapic6: CMCI unmasked lapic7: CMCI unmasked lapic4: CMCI unmasked lapic5: CMCI unmasked lapic2: CMCI unmasked lapic3: CMCI unmasked SMP: AP CPU #1 Launched! cpu1 AP: ID: 0x00000001 VER: 0x01060015 LDR: 0x00000002 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000100f2 SMP: AP CPU #4 Launched! cpu4 AP: ID: 0x00000004 VER: 0x01060015 LDR: 0x00000010 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: AP CPU #5 Launched! cpu5 AP: ID: 0x00000005 VER: 0x01060015 LDR: 0x00000020 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: AP CPU #3 Launched! cpu3 AP: ID: 0x00000003 VER: 0x01060015 LDR: 0x00000008 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: AP CPU #7 Launched! cpu7 AP: ID: 0x00000007 VER: 0x01060015 LDR: 0x00000080 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: AP CPU #6 Launched! cpu6 AP: ID: 0x00000006 VER: 0x01060015 LDR: 0x00000040 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: AP CPU #2 Launched! cpu2 AP: ID: 0x00000002 VER: 0x01060015 LDR: 0x00000004 DFR: 0x00000000 x2APIC: 1 lint0: 0x00010700 lint1: 0x00000400 TPR: 0x00000000 SVR: 0x000011ff timer: 0x000100ef therm: 0x00010000 err: 0x000000f0 pmc: 0x00010400 cmci: 0x000000f2 SMP: passed TSC synchronization test TSC timecounter discards lower 1 bit(s) Timecounter "TSC-low" frequency 1746068062 Hz quality 1000 random: entropy device external interface snd_unit_init() u=0x00ff8000 [512] d=0x00007c00 [32] c=0x000003ff [1024] feeder_register: snd_unit=-1 snd_maxautovchans=16 latency=5 feeder_rate_min=1 feeder_rate_max=2016000 feeder_rate_round=25 kbd: new array size 4 kbd1 at kbdmux0 mem: null: module_register_init: MOD_LOAD (vesa, 0xffffffff8087cc10, 0) error 19 io: random: registering fast source Intel Secure Key RNG random: fast provider: "Intel Secure Key RNG" nfslock: pseudo-device crypto: nvidia-modeset: Loading NVIDIA Kernel Mode Setting Driver for UNIX platforms 384.98 Thu Oct 26 09:43:40 PDT 2017 nexus0 vtvga0: on motherboard random: harvesting attach, 8 bytes (4 bits) from vtvga0 random: harvesting attach, 8 bytes (4 bits) from ram0 cryptosoft0: on motherboard crypto: assign cryptosoft0 driver id 0, flags 100663296 crypto: cryptosoft0 registers alg 1 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 2 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 3 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 4 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 5 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 16 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 6 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 7 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 18 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 19 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 20 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 8 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 15 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 9 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 10 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 13 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 14 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 11 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 22 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 23 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 25 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 24 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 26 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 27 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 28 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 21 flags 0 maxoplen 0 crypto: cryptosoft0 registers alg 17 flags 0 maxoplen 0 random: harvesting attach, 8 bytes (4 bits) from cryptosoft0 acpi0: on motherboard ACPI: Executed 1 blocks of module-level executable AML code ACPI: 4 ACPI AML tables successfully acquired and loaded PCIe: Memory Mapped configuration base @ 0xf8000000 ioapic0: routing intpin 9 (ISA IRQ 9) to lapic 0 vector 48 acpi0: Power Button (fixed) random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource0 random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource1 random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource2 random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource3 random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource4 random: harvesting attach, 8 bytes (4 bits) from acpi_sysresource5 cpu0: Processor \134_PR_.CPU0 (ACPI ID 1) -> APIC ID 0 cpu0: on acpi0 ACPI: Dynamic OEM Table Load: ACPI: SSDT 0xFFFFF8000A58C000 00083B (v01 PmRef Cpu0Cst 00003001 INTL 20051117) random: harvesting attach, 8 bytes (4 bits) from cpu0 cpu1: Processor \134_PR_.CPU1 (ACPI ID 2) -> APIC ID 2 cpu1: on acpi0 ACPI: Dynamic OEM Table Load: ACPI: SSDT 0xFFFFF8000A456800 000303 (v01 PmRef ApIst 00003000 INTL 20051117) ACPI: Dynamic OEM Table Load: ACPI: SSDT 0xFFFFF80006E81800 000119 (v01 PmRef ApCst 00003000 INTL 20051117) random: harvesting attach, 8 bytes (4 bits) from cpu1 cpu2: Processor \134_PR_.CPU2 (ACPI ID 3) -> APIC ID 4 cpu2: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu2 cpu3: Processor \134_PR_.CPU3 (ACPI ID 4) -> APIC ID 6 cpu3: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu3 cpu4: Processor \134_PR_.CPU4 (ACPI ID 5) -> APIC ID 1 cpu4: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu4 cpu5: Processor \134_PR_.CPU5 (ACPI ID 6) -> APIC ID 3 cpu5: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu5 cpu6: Processor \134_PR_.CPU6 (ACPI ID 7) -> APIC ID 5 cpu6: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu6 cpu7: Processor \134_PR_.CPU7 (ACPI ID 8) -> APIC ID 7 cpu7: on acpi0 random: harvesting attach, 8 bytes (4 bits) from cpu7 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 hpet0: vendor 0x8086, rev 0x1, 14318180Hz 64bit, 8 timers, legacy route hpet0: t0: irqs 0x00f00000 (0), MSI, 64bit, periodic hpet0: t1: irqs 0x00f00000 (0), MSI hpet0: t2: irqs 0x00f00800 (0), MSI hpet0: t3: irqs 0x00f01000 (0), MSI hpet0: t4: irqs 0x00000000 (0), MSI hpet0: t5: irqs 0x00000000 (0), MSI hpet0: t6: irqs 0x00000000 (0), MSI hpet0: t7: irqs 0x00000000 (0), MSI Timecounter "HPET" frequency 14318180 Hz quality 950 msi: routing MSI-X IRQ 256 to local APIC 2 vector 48 msi: routing MSI-X IRQ 257 to local APIC 4 vector 48 msi: routing MSI-X IRQ 258 to local APIC 6 vector 48 msi: routing MSI-X IRQ 259 to local APIC 0 vector 49 msi: routing MSI-X IRQ 260 to local APIC 2 vector 49 msi: routing MSI-X IRQ 261 to local APIC 4 vector 49 msi: routing MSI-X IRQ 262 to local APIC 6 vector 49 msi: routing MSI-X IRQ 263 to local APIC 0 vector 50 msi: Assigning MSI-X IRQ 256 to local APIC 0 vector 51 msi: Assigning MSI-X IRQ 257 to local APIC 1 vector 48 msi: Assigning MSI-X IRQ 258 to local APIC 2 vector 48 msi: Assigning MSI-X IRQ 259 to local APIC 3 vector 48 msi: Assigning MSI-X IRQ 260 to local APIC 4 vector 48 msi: Assigning MSI-X IRQ 261 to local APIC 5 vector 48 msi: Assigning MSI-X IRQ 263 to local APIC 7 vector 48 Event timer "HPET" frequency 14318180 Hz quality 550 random: harvesting attach, 8 bytes (4 bits) from hpet0 atrtc0: port 0x70-0x77 irq 8 on acpi0 atrtc0: Warning: Couldn't map I/O. atrtc0: registered as a time-of-day clock (resolution 1000000us, adjustment 0.500000000s) ioapic0: routing intpin 8 (ISA IRQ 8) to lapic 2 vector 49 ioapic0: routing intpin 8 (ISA IRQ 8) to lapic 0 vector 49 Event timer "RTC" frequency 32768 Hz quality 0 random: harvesting attach, 8 bytes (4 bits) from atrtc0 attimer0: port 0x40-0x43,0x50-0x53 irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 ioapic0: routing intpin 2 (ISA IRQ 0) to lapic 4 vector 49 Event timer "i8254" frequency 1193182 Hz quality 100 random: harvesting attach, 8 bytes (4 bits) from attimer0 ACPI timer: 1/1 1/1 1/2 1/1 1/2 1/1 1/1 1/1 1/1 1/2 -> 10 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0 random: harvesting attach, 8 bytes (4 bits) from acpi_timer0 pci_link0: Index IRQ Rtd Ref IRQs Initial Probe 0 11 N 0 3 4 5 6 10 11 12 14 15 Validation 0 11 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link0 pci_link1: Index IRQ Rtd Ref IRQs Initial Probe 0 10 N 0 3 4 5 6 10 11 12 14 15 Validation 0 10 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link1 pci_link2: Index IRQ Rtd Ref IRQs Initial Probe 0 3 N 0 3 4 5 6 10 11 12 14 15 Validation 0 3 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link2 pci_link3: Index IRQ Rtd Ref IRQs Initial Probe 0 5 N 0 3 4 5 6 10 11 12 14 15 Validation 0 5 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link3 pci_link4: Index IRQ Rtd Ref IRQs Initial Probe 0 255 N 0 3 4 5 6 10 11 12 14 15 Validation 0 255 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link4 pci_link5: Index IRQ Rtd Ref IRQs Initial Probe 0 255 N 0 3 4 5 6 10 11 12 14 15 Validation 0 255 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link5 pci_link6: Index IRQ Rtd Ref IRQs Initial Probe 0 11 N 0 3 4 5 6 10 11 12 14 15 Validation 0 11 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link6 pci_link7: Index IRQ Rtd Ref IRQs Initial Probe 0 10 N 0 3 4 5 6 10 11 12 14 15 Validation 0 10 N 0 3 4 5 6 10 11 12 14 15 After Disable 0 255 N 0 3 4 5 6 10 11 12 14 15 random: harvesting attach, 8 bytes (4 bits) from pci_link7 pcib0: port 0xcf8-0xcff on acpi0 pcib0: _OSC returned error 0x10 pcib0: decoding 5 range 0-0x3e pcib0: decoding 4 range 0-0xcf7 pcib0: decoding 4 range 0xd00-0xffff pcib0: decoding 3 range 0xa0000-0xbffff pcib0: decoding 3 range 0xd0000-0xd3fff pcib0: decoding 3 range 0xd4000-0xd7fff pcib0: decoding 3 range 0xd8000-0xdbfff pcib0: decoding 3 range 0xdc000-0xdffff pcib0: decoding 3 range 0xe0000-0xe3fff pcib0: decoding 3 range 0xe4000-0xe7fff pcib0: decoding 3 range 0xe0000000-0xfeafffff pci0: on pcib0 pci0: domain=0, physical bus=0 found-> vendor=0x8086, dev=0x0158, revid=0x09 domain=0, bus=0, slot=0, func=0 class=06-00-00, hdrtype=0x00, mfdev=0 cmdreg=0x0006, statreg=0x2090, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) found-> vendor=0x8086, dev=0x0151, revid=0x09 domain=0, bus=0, slot=1, func=0 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 3 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.1.INTA pcib0: slot 1 INTA hardwired to IRQ 16 secbus=1, subbus=1 found-> vendor=0x8086, dev=0x015d, revid=0x09 domain=0, bus=0, slot=6, func=0 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=5 powerspec 3 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.6.INTA pcib0: slot 6 INTA hardwired to IRQ 19 secbus=2, subbus=2 found-> vendor=0x8086, dev=0x1e31, revid=0x04 domain=0, bus=0, slot=20, func=0 class=0c-03-30, hdrtype=0x00, mfdev=0 cmdreg=0x0006, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D3 current D0 MSI supports 8 messages, 64 bit map[10]: type Memory, range 64, base 0xf3500000, size 16, enabled pcib0: allocated type 3 (0xf3500000-0xf350ffff) for rid 10 of pci0:0:20:0 pcib0: matched entry for 0.20.INTA pcib0: slot 20 INTA hardwired to IRQ 16 found-> vendor=0x8086, dev=0x1e3a, revid=0x04 domain=0, bus=0, slot=22, func=0 class=07-80-00, hdrtype=0x00, mfdev=1 cmdreg=0x0006, statreg=0x0010, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 3 supports D0 D3 current D0 MSI supports 1 message, 64 bit map[10]: type Memory, range 64, base 0xf351b000, size 4, enabled pcib0: allocated type 3 (0xf351b000-0xf351b00f) for rid 10 of pci0:0:22:0 pcib0: matched entry for 0.22.INTA pcib0: slot 22 INTA hardwired to IRQ 16 found-> vendor=0x8086, dev=0x1e2d, revid=0x04 domain=0, bus=0, slot=26, func=0 class=0c-03-20, hdrtype=0x00, mfdev=0 cmdreg=0x0006, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D3 current D0 map[10]: type Memory, range 32, base 0xf3518000, size 10, enabled pcib0: allocated type 3 (0xf3518000-0xf35183ff) for rid 10 of pci0:0:26:0 pcib0: matched entry for 0.26.INTA pcib0: slot 26 INTA hardwired to IRQ 16 ehci early: SMM active, request owner change found-> vendor=0x8086, dev=0x1e20, revid=0x04 domain=0, bus=0, slot=27, func=0 class=04-03-00, hdrtype=0x00, mfdev=0 cmdreg=0x0006, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D3 current D0 MSI supports 1 message, 64 bit map[10]: type Memory, range 64, base 0xf3510000, size 14, enabled pcib0: allocated type 3 (0xf3510000-0xf3513fff) for rid 10 of pci0:0:27:0 pcib0: matched entry for 0.27.INTA pcib0: slot 27 INTA hardwired to IRQ 22 found-> vendor=0x8086, dev=0x1e10, revid=0xc4 domain=0, bus=0, slot=28, func=0 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.28.INTA pcib0: slot 28 INTA hardwired to IRQ 16 secbus=3, subbus=3 found-> vendor=0x8086, dev=0x1e18, revid=0xc4 domain=0, bus=0, slot=28, func=4 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.28.INTA pcib0: slot 28 INTA hardwired to IRQ 16 secbus=4, subbus=4 found-> vendor=0x8086, dev=0x1e1a, revid=0xc4 domain=0, bus=0, slot=28, func=5 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=10 powerspec 2 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.28.INTB pcib0: slot 28 INTB hardwired to IRQ 17 secbus=5, subbus=5 found-> vendor=0x8086, dev=0x1e1c, revid=0xc4 domain=0, bus=0, slot=28, func=6 class=06-04-00, hdrtype=0x01, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=c, irq=3 powerspec 2 supports D0 D3 current D0 MSI supports 1 message pcib0: matched entry for 0.28.INTC pcib0: slot 28 INTC hardwired to IRQ 18 secbus=6, subbus=6 found-> vendor=0x8086, dev=0x1e26, revid=0x04 domain=0, bus=0, slot=29, func=0 class=0c-03-20, hdrtype=0x00, mfdev=0 cmdreg=0x0006, statreg=0x0290, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=10 powerspec 2 supports D0 D3 current D0 map[10]: type Memory, range 32, base 0xf3517000, size 10, enabled pcib0: allocated type 3 (0xf3517000-0xf35173ff) for rid 10 of pci0:0:29:0 pcib0: matched entry for 0.29.INTA pcib0: slot 29 INTA hardwired to IRQ 23 ehci early: SMM active, request owner change found-> vendor=0x8086, dev=0x244e, revid=0xa4 domain=0, bus=0, slot=30, func=0 class=06-04-01, hdrtype=0x01, mfdev=0 cmdreg=0x0007, statreg=0x0010, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) secbus=7, subbus=7 found-> vendor=0x8086, dev=0x1e53, revid=0x04 domain=0, bus=0, slot=31, func=0 class=06-01-00, hdrtype=0x00, mfdev=1 cmdreg=0x0007, statreg=0x0210, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) found-> vendor=0x8086, dev=0x1e02, revid=0x04 domain=0, bus=0, slot=31, func=2 class=01-06-01, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x02b0, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=5 powerspec 3 supports D0 D3 current D0 MSI supports 1 message map[10]: type I/O Port, range 32, base 0xf070, size 3, enabled pcib0: allocated type 4 (0xf070-0xf077) for rid 10 of pci0:0:31:2 map[14]: type I/O Port, range 32, base 0xf060, size 2, enabled pcib0: allocated type 4 (0xf060-0xf063) for rid 14 of pci0:0:31:2 map[18]: type I/O Port, range 32, base 0xf050, size 3, enabled pcib0: allocated type 4 (0xf050-0xf057) for rid 18 of pci0:0:31:2 map[1c]: type I/O Port, range 32, base 0xf040, size 2, enabled pcib0: allocated type 4 (0xf040-0xf043) for rid 1c of pci0:0:31:2 map[20]: type I/O Port, range 32, base 0xf020, size 5, enabled pcib0: allocated type 4 (0xf020-0xf03f) for rid 20 of pci0:0:31:2 map[24]: type Memory, range 32, base 0xf3516000, size 11, enabled pcib0: allocated type 3 (0xf3516000-0xf35167ff) for rid 24 of pci0:0:31:2 pcib0: matched entry for 0.31.INTB pcib0: slot 31 INTB hardwired to IRQ 19 found-> vendor=0x8086, dev=0x1e22, revid=0x04 domain=0, bus=0, slot=31, func=3 class=0c-05-00, hdrtype=0x00, mfdev=0 cmdreg=0x0003, statreg=0x0280, cachelnsz=0 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=c, irq=3 map[10]: type Memory, range 64, base 0xf3515000, size 8, enabled pcib0: allocated type 3 (0xf3515000-0xf35150ff) for rid 10 of pci0:0:31:3 map[20]: type I/O Port, range 32, base 0xf000, size 5, enabled pcib0: allocated type 4 (0xf000-0xf01f) for rid 20 of pci0:0:31:3 pcib0: matched entry for 0.31.INTC pcib0: slot 31 INTC hardwired to IRQ 18 random: harvesting attach, 8 bytes (4 bits) from hostb0 pcib1: irq 16 at device 1.0 on pci0 pcib0: allocated type 4 (0xe000-0xefff) for rid 1c of pcib1 pcib0: allocated type 3 (0xe0000000-0xf30fffff) for rid 20 of pcib1 pcib1: domain 0 pcib1: secondary bus 1 pcib1: subordinate bus 1 pcib1: I/O decode 0xe000-0xefff pcib1: memory decode 0xe0000000-0xf30fffff pcib1: special decode VGA pci1: on pcib1 pcib1: allocated bus range (1-1) for rid 0 of pci1 pci1: domain=0, physical bus=1 found-> vendor=0x10de, dev=0x0fc1, revid=0xa1 domain=0, bus=1, slot=0, func=0 class=03-00-00, hdrtype=0x00, mfdev=1 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 3 supports D0 D3 current D0 MSI supports 1 message, 64 bit map[10]: type Memory, range 32, base 0xf2000000, size 24, enabled pcib1: allocated memory range (0xf2000000-0xf2ffffff) for rid 10 of pci0:1:0:0 map[14]: type Prefetchable Memory, range 64, base 0xe0000000, size 28, enabled pcib1: allocated memory range (0xe0000000-0xefffffff) for rid 14 of pci0:1:0:0 map[1c]: type Prefetchable Memory, range 64, base 0xf0000000, size 25, enabled pcib1: allocated memory range (0xf0000000-0xf1ffffff) for rid 1c of pci0:1:0:0 map[24]: type I/O Port, range 32, base 0xe000, size 7, enabled pcib1: allocated I/O port range (0xe000-0xe07f) for rid 24 of pci0:1:0:0 pcib1: matched entry for 1.0.INTA pcib1: slot 0 INTA hardwired to IRQ 16 found-> vendor=0x10de, dev=0x0e1b, revid=0xa1 domain=0, bus=1, slot=0, func=1 class=04-03-00, hdrtype=0x00, mfdev=1 cmdreg=0x0006, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=b, irq=10 powerspec 3 supports D0 D3 current D0 MSI supports 1 message, 64 bit map[10]: type Memory, range 32, base 0xf3080000, size 14, enabled pcib1: allocated memory range (0xf3080000-0xf3083fff) for rid 10 of pci0:1:0:1 pcib1: matched entry for 1.0.INTB pcib1: slot 0 INTB hardwired to IRQ 17 vgapci0: port 0xe000-0xe07f mem 0xf2000000-0xf2ffffff,0xe0000000-0xefffffff,0xf0000000-0xf1ffffff irq 16 at device 0.0 on pci1 nvidia0: on vgapci0 vgapci0: child nvidia0 requested pci_enable_io vgapci0: attempting to allocate 1 MSI vectors (1 supported) msi: routing MSI IRQ 264 to local APIC 6 vector 48 vgapci0: using IRQ 264 for MSI vgapci0: child nvidia0 requested pci_enable_io random: harvesting attach, 8 bytes (4 bits) from nvidia0 vgapci0: Boot video device random: harvesting attach, 8 bytes (4 bits) from vgapci0 hdac0: mem 0xf3080000-0xf3083fff irq 17 at device 0.1 on pci1 hdac0: PCI card vendor: 0x3842, device: 0x2645 hdac0: HDA Driver Revision: 20120126_0002 hdac0: Config options: on=0x00000000 off=0x00000000 hdac0: attempting to allocate 1 MSI vectors (1 supported) msi: routing MSI IRQ 265 to local APIC 0 vector 50 hdac0: using IRQ 265 for MSI hdac0: Caps: OSS 4, ISS 4, BSS 0, NSDO 4, 64bit, CORB 256, RIRB 256 random: harvesting attach, 8 bytes (4 bits) from hdac0 random: harvesting attach, 8 bytes (4 bits) from pci1 random: harvesting attach, 8 bytes (4 bits) from pcib1 pcib2: irq 19 at device 6.0 on pci0 pcib2: domain 0 pcib2: secondary bus 2 pcib2: subordinate bus 2 pci2: on pcib2 pcib2: allocated bus range (2-2) for rid 0 of pci2 pci2: domain=0, physical bus=2 random: harvesting attach, 8 bytes (4 bits) from pci2 random: harvesting attach, 8 bytes (4 bits) from pcib2 xhci0: mem 0xf3500000-0xf350ffff irq 16 at device 20.0 on pci0 xhci0: 32 bytes context size, 64-bit DMA xhci0: attempting to allocate 1 MSI vectors (8 supported) msi: routing MSI IRQ 266 to local APIC 2 vector 49 xhci0: using IRQ 266 for MSI xhci0: MSI enabled xhci0: Port routing mask set to 0xffffffff usbus0 on xhci0 xhci0: usbpf: Attached random: harvesting attach, 8 bytes (4 bits) from usbus0 usbus0: random: harvesting attach, 8 bytes (4 bits) from xhci0 5.0Gbps Super Speed USB v3.0 pci0: at device 22.0 (no driver attached) ehci0: mem 0xf3518000-0xf35183ff irq 16 at device 26.0 on pci0 ioapic0: routing intpin 16 (PCI IRQ 16) to lapic 4 vector 50 usbus1: EHCI version 1.0 usbus1 on ehci0 ehci0: usbpf: Attached random: harvesting attach, 8 bytes (4 bits) from usbus1 usbus1: random: harvesting attach, 8 bytes (4 bits) from ehci0 480Mbps High Speed USB v2.0 hdac1: mem 0xf3510000-0xf3513fff irq 22 at device 27.0 on pci0 hdac1: PCI card vendor: 0x1043, device: 0x84fb hdac1: HDA Driver Revision: 20120126_0002 hdac1: Config options: on=0x00000000 off=0x00000000 hdac1: attempting to allocate 1 MSI vectors (1 supported) msi: routing MSI IRQ 267 to local APIC 6 vector 50 hdac1: using IRQ 267 for MSI hdac1: Caps: OSS 4, ISS 4, BSS 0, NSDO 1, 64bit, CORB 256, RIRB 256 random: harvesting attach, 8 bytes (4 bits) from hdac1 pcib3: irq 16 at device 28.0 on pci0 pcib3: domain 0 pcib3: secondary bus 3 pcib3: subordinate bus 3 pci3: on pcib3 pcib3: allocated bus range (3-3) for rid 0 of pci3 pci3: domain=0, physical bus=3 random: harvesting attach, 8 bytes (4 bits) from pci3 random: harvesting attach, 8 bytes (4 bits) from pcib3 pcib4: irq 16 at device 28.4 on pci0 pcib0: allocated type 4 (0xd000-0xdfff) for rid 1c of pcib4 pcib0: allocated type 3 (0xf3400000-0xf34fffff) for rid 20 of pcib4 pcib4: domain 0 pcib4: secondary bus 4 pcib4: subordinate bus 4 pcib4: I/O decode 0xd000-0xdfff pcib4: memory decode 0xf3400000-0xf34fffff pci4: on pcib4 pcib4: allocated bus range (4-4) for rid 0 of pci4 pci4: domain=0, physical bus=4 found-> vendor=0x1095, dev=0x3132, revid=0x01 domain=0, bus=4, slot=0, func=0 class=01-06-00, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=11 powerspec 2 supports D0 D1 D2 D3 current D0 MSI supports 1 message, 64 bit map[10]: type Memory, range 64, base 0xf3484000, size 7, enabled pcib4: allocated memory range (0xf3484000-0xf348407f) for rid 10 of pci0:4:0:0 map[18]: type Memory, range 64, base 0xf3480000, size 14, enabled pcib4: allocated memory range (0xf3480000-0xf3483fff) for rid 18 of pci0:4:0:0 map[20]: type I/O Port, range 32, base 0xd000, size 7, enabled pcib4: allocated I/O port range (0xd000-0xd07f) for rid 20 of pci0:4:0:0 pcib4: matched entry for 4.0.INTA pcib4: slot 0 INTA hardwired to IRQ 16 pci4: at device 0.0 (no driver attached) random: harvesting attach, 8 bytes (4 bits) from pci4 random: harvesting attach, 8 bytes (4 bits) from pcib4 pcib5: irq 17 at device 28.5 on pci0 pcib0: allocated type 4 (0xc000-0xcfff) for rid 1c of pcib5 pcib0: allocated type 3 (0xf3300000-0xf33fffff) for rid 20 of pcib5 pcib5: domain 0 pcib5: secondary bus 5 pcib5: subordinate bus 5 pcib5: I/O decode 0xc000-0xcfff pcib5: memory decode 0xf3300000-0xf33fffff pci5: on pcib5 pcib5: allocated bus range (5-5) for rid 0 of pci5 pci5: domain=0, physical bus=5 found-> vendor=0x8086, dev=0x10d3, revid=0x00 domain=0, bus=5, slot=0, func=0 class=02-00-00, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=10 powerspec 2 supports D0 D3 current D0 MSI supports 1 message, 64 bit MSI-X supports 5 messages in map 0x1c map[10]: type Memory, range 32, base 0xf3300000, size 17, enabled pcib5: allocated memory range (0xf3300000-0xf331ffff) for rid 10 of pci0:5:0:0 map[18]: type I/O Port, range 32, base 0xc000, size 5, enabled pcib5: allocated I/O port range (0xc000-0xc01f) for rid 18 of pci0:5:0:0 map[1c]: type Memory, range 32, base 0xf3320000, size 14, enabled pcib5: allocated memory range (0xf3320000-0xf3323fff) for rid 1c of pci0:5:0:0 pcib5: matched entry for 5.0.INTA pcib5: slot 0 INTA hardwired to IRQ 17 em0: port 0xc000-0xc01f mem 0xf3300000-0xf331ffff,0xf3320000-0xf3323fff irq 17 at device 0.0 on pci5 em0: attempting to allocate 3 MSI-X vectors (5 supported) msi: routing MSI-X IRQ 268 to local APIC 0 vector 52 msi: routing MSI-X IRQ 269 to local APIC 2 vector 50 msi: routing MSI-X IRQ 270 to local APIC 4 vector 51 em0: using IRQs 268-270 for MSI-X em0: Using MSIX interrupts with 3 vectors msi: Assigning MSI-X IRQ 269 to local APIC 1 vector 49 em0: bpf attached em0: Ethernet address: xx:xx:xx:xx:xx:xx random: harvesting attach, 8 bytes (4 bits) from em0 random: harvesting attach, 8 bytes (4 bits) from pci5 random: harvesting attach, 8 bytes (4 bits) from pcib5 pcib6: irq 18 at device 28.6 on pci0 pcib0: allocated type 4 (0xb000-0xbfff) for rid 1c of pcib6 pcib0: allocated type 3 (0xf3200000-0xf32fffff) for rid 20 of pcib6 pcib6: domain 0 pcib6: secondary bus 6 pcib6: subordinate bus 6 pcib6: I/O decode 0xb000-0xbfff pcib6: memory decode 0xf3200000-0xf32fffff pci6: on pcib6 pcib6: allocated bus range (6-6) for rid 0 of pci6 pci6: domain=0, physical bus=6 found-> vendor=0x8086, dev=0x10d3, revid=0x00 domain=0, bus=6, slot=0, func=0 class=02-00-00, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x0010, cachelnsz=16 (dwords) lattimer=0x00 (0 ns), mingnt=0x00 (0 ns), maxlat=0x00 (0 ns) intpin=a, irq=3 powerspec 2 supports D0 D3 current D0 MSI supports 1 message, 64 bit MSI-X supports 5 messages in map 0x1c map[10]: type Memory, range 32, base 0xf3200000, size 17, enabled pcib6: allocated memory range (0xf3200000-0xf321ffff) for rid 10 of pci0:6:0:0 map[18]: type I/O Port, range 32, base 0xb000, size 5, enabled pcib6: allocated I/O port range (0xb000-0xb01f) for rid 18 of pci0:6:0:0 map[1c]: type Memory, range 32, base 0xf3220000, size 14, enabled pcib6: allocated memory range (0xf3220000-0xf3223fff) for rid 1c of pci0:6:0:0 pcib6: matched entry for 6.0.INTA pcib6: slot 0 INTA hardwired to IRQ 18 em1: port 0xb000-0xb01f mem 0xf3200000-0xf321ffff,0xf3220000-0xf3223fff irq 18 at device 0.0 on pci6 em1: attempting to allocate 3 MSI-X vectors (5 supported) msi: routing MSI-X IRQ 271 to local APIC 6 vector 51 msi: routing MSI-X IRQ 272 to local APIC 0 vector 53 msi: routing MSI-X IRQ 273 to local APIC 2 vector 50 em1: using IRQs 271-273 for MSI-X em1: Using MSIX interrupts with 3 vectors msi: Assigning MSI-X IRQ 271 to local APIC 2 vector 51 msi: Assigning MSI-X IRQ 272 to local APIC 3 vector 49 em1: bpf attached em1: Ethernet address: xx:xx:xx:xx:xx:xx random: harvesting attach, 8 bytes (4 bits) from em1 random: harvesting attach, 8 bytes (4 bits) from pci6 random: harvesting attach, 8 bytes (4 bits) from pcib6 ehci1: mem 0xf3517000-0xf35173ff irq 23 at device 29.0 on pci0 ioapic0: routing intpin 23 (PCI IRQ 23) to lapic 4 vector 52 usbus2: EHCI version 1.0 usbus2 on ehci1 ehci1: usbpf: Attached random: harvesting attach, 8 bytes (4 bits) from usbus2 usbus2: random: harvesting attach, 8 bytes (4 bits) from ehci1 480Mbps High Speed USB v2.0 pcib7: at device 30.0 on pci0 pcib0: allocated type 4 (0xa000-0xafff) for rid 1c of pcib7 pcib0: allocated type 3 (0xf3100000-0xf31fffff) for rid 20 of pcib7 pcib7: domain 0 pcib7: secondary bus 7 pcib7: subordinate bus 7 pcib7: I/O decode 0xa000-0xafff pcib7: memory decode 0xf3100000-0xf31fffff pcib7: special decode subtractive pci7: on pcib7 pcib7: allocated bus range (7-7) for rid 0 of pci7 pci7: domain=0, physical bus=7 found-> vendor=0x1106, dev=0x3044, revid=0xc0 domain=0, bus=7, slot=3, func=0 class=0c-00-10, hdrtype=0x00, mfdev=0 cmdreg=0x0007, statreg=0x0210, cachelnsz=16 (dwords) lattimer=0x20 (960 ns), mingnt=0x00 (0 ns), maxlat=0x20 (8000 ns) intpin=a, irq=5 powerspec 2 supports D0 D2 D3 current D0 map[10]: type Memory, range 32, base 0xf3100000, size 11, enabled pcib7: allocated memory range (0xf3100000-0xf31007ff) for rid 10 of pci0:7:3:0 map[14]: type I/O Port, range 32, base 0xa000, size 7, enabled pcib7: allocated I/O port range (0xa000-0xa07f) for rid 14 of pci0:7:3:0 pcib7: matched entry for 7.3.INTA pcib7: slot 3 INTA hardwired to IRQ 19 pci7: at device 3.0 (no driver attached) random: harvesting attach, 8 bytes (4 bits) from pci7 random: harvesting attach, 8 bytes (4 bits) from pcib7 isab0: at device 31.0 on pci0 isa0: on isab0 random: harvesting attach, 8 bytes (4 bits) from isa0 random: harvesting attach, 8 bytes (4 bits) from isab0 ahci0: port 0xf070-0xf077,0xf060-0xf063,0xf050-0xf057,0xf040-0xf043,0xf020-0xf03f mem 0xf3516000-0xf35167ff irq 19 at device 31.2 on pci0 ahci0: attempting to allocate 1 MSI vectors (1 supported) msi: routing MSI IRQ 274 to local APIC 6 vector 51 ahci0: using IRQ 274 for MSI ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not supported ahci0: Caps: 64bit NCQ AL CLO 6Gbps PMD SSC PSC 32cmd EM 6ports ahci0: Caps2: APST ahcich0: at channel 0 on ahci0 ahcich0: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich0 ahcich1: at channel 1 on ahci0 ahcich1: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich1 ahcich2: at channel 2 on ahci0 ahcich2: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich2 ahcich3: at channel 3 on ahci0 ahcich3: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich3 ahcich4: at channel 4 on ahci0 ahcich4: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich4 ahcich5: at channel 5 on ahci0 ahcich5: Caps: random: harvesting attach, 8 bytes (4 bits) from ahcich5 ahciem0: on ahci0 ahciem0: Caps: ALHD XMT SMB LED random: harvesting attach, 8 bytes (4 bits) from ahciem0 random: harvesting attach, 8 bytes (4 bits) from ahci0 pci0: at device 31.3 (no driver attached) random: harvesting attach, 8 bytes (4 bits) from pci0 random: harvesting attach, 8 bytes (4 bits) from pcib0 acpi_button0: on acpi0 random: harvesting attach, 8 bytes (4 bits) from acpi_button0 acpi_tz0: on acpi0 random: harvesting attach, 8 bytes (4 bits) from acpi_tz0 acpi_tz1: on acpi0 random: harvesting attach, 8 bytes (4 bits) from acpi_tz1 random: harvesting attach, 8 bytes (4 bits) from atdma0 random: harvesting attach, 8 bytes (4 bits) from fpupnp0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 atkbd: the current kbd controller command byte 0065 atkbd: keyboard ID 0x41ab (2) kbdc: RESET_KBD return code:00fa kbdc: RESET_KBD status:00aa kbd0 at atkbd0 kbd0: atkbd0, AT 101/102 (2), config:0x0, flags:0x1d0000 ioapic0: routing intpin 1 (ISA IRQ 1) to lapic 0 vector 53 atkbd0: [GIANT-LOCKED] random: harvesting attach, 8 bytes (4 bits) from atkbd0 psm0: unable to allocate IRQ random: harvesting attach, 8 bytes (4 bits) from atkbdc0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 ioapic0: routing intpin 4 (ISA IRQ 4) to lapic 2 vector 52 uart0: fast interrupt uart0: PPS capture mode: DCDinvalid random: harvesting attach, 8 bytes (4 bits) from uart0 ACPI: Enabled 5 GPEs in block 00 to 3F random: harvesting attach, 8 bytes (4 bits) from acpi0 random: harvesting attach, 8 bytes (4 bits) from apic0 acpi0: wakeup code va 0xfffffe085e7a9000 pa 0x99000 random: harvesting attach, 8 bytes (4 bits) from nexus0 pcib0: allocated type 3 (0xb0000-0xb07ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb0800-0xb0fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb1000-0xb17ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb1800-0xb1fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb2000-0xb27ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb2800-0xb2fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb3000-0xb37ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb3800-0xb3fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb4000-0xb47ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb4800-0xb4fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb5000-0xb57ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb5800-0xb5fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb6000-0xb67ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb6800-0xb6fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb7000-0xb77ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb7800-0xb7fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb8000-0xb87ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb8800-0xb8fff) for rid 0 of orm0 pcib0: allocated type 3 (0xb9000-0xb97ff) for rid 0 of orm0 pcib0: allocated type 3 (0xb9800-0xb9fff) for rid 0 of orm0 pcib0: allocated type 3 (0xba000-0xba7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xba800-0xbafff) for rid 0 of orm0 pcib0: allocated type 3 (0xbb000-0xbb7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xbb800-0xbbfff) for rid 0 of orm0 pcib0: allocated type 3 (0xbc000-0xbc7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xbc800-0xbcfff) for rid 0 of orm0 pcib0: allocated type 3 (0xbd000-0xbd7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xbd800-0xbdfff) for rid 0 of orm0 pcib0: allocated type 3 (0xbe000-0xbe7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xbe800-0xbefff) for rid 0 of orm0 pcib0: allocated type 3 (0xbf000-0xbf7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xbf800-0xbffff) for rid 0 of orm0 pcib0: allocated type 3 (0xd0000-0xd07ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd0800-0xd0fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd1000-0xd17ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd1800-0xd1fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd2000-0xd27ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd2800-0xd2fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd3000-0xd37ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd3800-0xd3fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd4000-0xd47ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd4800-0xd4fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd5000-0xd57ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd5800-0xd5fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd6000-0xd67ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd6800-0xd6fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd7000-0xd77ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd7800-0xd7fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd8000-0xd87ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd8800-0xd8fff) for rid 0 of orm0 pcib0: allocated type 3 (0xd9000-0xd97ff) for rid 0 of orm0 pcib0: allocated type 3 (0xd9800-0xd9fff) for rid 0 of orm0 pcib0: allocated type 3 (0xda000-0xda7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xda800-0xdafff) for rid 0 of orm0 pcib0: allocated type 3 (0xdb000-0xdb7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xdb800-0xdbfff) for rid 0 of orm0 pcib0: allocated type 3 (0xdc000-0xdc7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xdc800-0xdcfff) for rid 0 of orm0 pcib0: allocated type 3 (0xdd000-0xdd7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xdd800-0xddfff) for rid 0 of orm0 pcib0: allocated type 3 (0xde000-0xde7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xde800-0xdefff) for rid 0 of orm0 pcib0: allocated type 3 (0xdf000-0xdf7ff) for rid 0 of orm0 pcib0: allocated type 3 (0xdf800-0xdffff) for rid 0 of orm0 pcib0: allocated type 3 (0xe0000-0xe07ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe0800-0xe0fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe1000-0xe17ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe1800-0xe1fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe2000-0xe27ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe2800-0xe2fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe3000-0xe37ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe3800-0xe3fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe4000-0xe47ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe4800-0xe4fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe5000-0xe57ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe5800-0xe5fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe6000-0xe67ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe6800-0xe6fff) for rid 0 of orm0 pcib0: allocated type 3 (0xe7000-0xe77ff) for rid 0 of orm0 pcib0: allocated type 3 (0xe7800-0xe7fff) for rid 0 of orm0 isa_probe_children: disabling PnP devices ichwd0: on isa0 pcib0: allocated type 4 (0x430-0x437) for rid 0 of ichwd0 pcib0: allocated type 4 (0x460-0x47f) for rid 1 of ichwd0 ichwd0: timer disabled random: harvesting attach, 8 bytes (4 bits) from ichwd0 atkbdc: atkbdc0 already exists; skipping it atrtc: atrtc0 already exists; skipping it attimer: attimer0 already exists; skipping it sc: sc0 already exists; skipping it uart: uart0 already exists; skipping it isa_probe_children: probing non-PnP devices sc0 failed to probe on isa0 vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 pcib0: allocated type 4 (0x3c0-0x3df) for rid 0 of vga0 VESA: INT 0x10 vector 0xc000:0x1965 VESA: information block 0000 56 45 53 41 00 03 00 01 00 93 01 00 00 00 22 00 0010 00 93 e0 00 07 80 07 01 00 93 1a 01 00 93 31 01 0020 00 93 00 01 01 01 02 01 03 01 04 01 05 01 06 01 0030 07 01 0e 01 0f 01 11 01 12 01 14 01 15 01 17 01 0040 18 01 1a 01 1b 01 30 01 31 01 32 01 33 01 34 01 0050 35 01 36 01 3d 01 3e 01 45 01 46 01 4a 01 4b 01 0060 4c 01 4d 01 60 01 61 01 ff ff 00 00 00 00 00 00 0070 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0090 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00b0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00c0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00d0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00f0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0100 4e 56 49 44 49 41 00 4e 56 49 44 49 41 20 43 6f 0110 72 70 6f 72 61 74 69 6f 6e 00 47 4b 31 30 37 20 0120 42 6f 61 72 64 20 2d 20 32 30 31 31 30 30 30 30 0130 00 43 68 69 70 20 52 65 76 00 00 00 00 00 00 00 0140 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0150 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0170 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0180 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0190 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01b0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01c0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01d0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01e0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01f0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 VESA: 35 mode(s) found random: harvesting attach, 8 bytes (4 bits) from vga0 fdc0 failed to probe at port 0x3f0 irq 6 drq 2 on isa0 ppc0 failed to probe at irq 7 on isa0 pcib0: allocated type 4 (0x2f8-0x2f8) for rid 0 of uart1 uart1 failed to probe at port 0x2f8 irq 3 on isa0 isa_probe_children: probing PnP devices AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf0 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf1 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf2 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf3 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf4 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf5 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf6 AcpiOsExecute: task queue not started random: harvesting attach, 8 bytes (4 bits) from acpi_perf7 est0: on cpu0 random: harvesting attach, 8 bytes (4 bits) from cpufreq0 random: harvesting attach, 8 bytes (4 bits) from est0 est1: on cpu1 random: harvesting attach, 8 bytes (4 bits) from cpufreq1 random: harvesting attach, 8 bytes (4 bits) from est1 est2: on cpu2 random: harvesting attach, 8 bytes (4 bits) from cpufreq2 random: harvesting attach, 8 bytes (4 bits) from est2 est3: on cpu3 random: harvesting attach, 8 bytes (4 bits) from cpufreq3 random: harvesting attach, 8 bytes (4 bits) from est3 est4: on cpu4 random: harvesting attach, 8 bytes (4 bits) from cpufreq4 random: harvesting attach, 8 bytes (4 bits) from est4 est5: on cpu5 random: harvesting attach, 8 bytes (4 bits) from cpufreq5 random: harvesting attach, 8 bytes (4 bits) from est5 est6: on cpu6 random: harvesting attach, 8 bytes (4 bits) from cpufreq6 random: harvesting attach, 8 bytes (4 bits) from est6 est7: on cpu7 random: harvesting attach, 8 bytes (4 bits) from cpufreq7 random: harvesting attach, 8 bytes (4 bits) from est7 Device configuration finished. procfs registered ZFS filesystem version: 5 ZFS storage pool version: features support (5000) lapic: Divisor 2, Frequency 49887674 Hz lapic: deadline tsc mode, Frequency 3492136124 Hz Timecounters tick every 1.000 msec --pf9I7BMVVzbSWLtt-- From owner-freebsd-stable@freebsd.org Sun Dec 31 16:47:51 2017 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id A3747E86146 for ; Sun, 31 Dec 2017 16:47:51 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4A9BA799B7; Sun, 31 Dec 2017 16:47:51 +0000 (UTC) (envelope-from kostikbel@gmail.com) Received: from tom.home (kib@localhost [127.0.0.1]) by kib.kiev.ua (8.15.2/8.15.2) with ESMTPS id vBVGlc8p002864 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Sun, 31 Dec 2017 18:47:41 +0200 (EET) (envelope-from kostikbel@gmail.com) DKIM-Filter: OpenDKIM Filter v2.10.3 kib.kiev.ua vBVGlc8p002864 Received: (from kostik@localhost) by tom.home (8.15.2/8.15.2/Submit) id vBVGlcQm002863; Sun, 31 Dec 2017 18:47:38 +0200 (EET) (envelope-from kostikbel@gmail.com) X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com using -f Date: Sun, 31 Dec 2017 18:47:38 +0200 From: Konstantin Belousov To: Gary Palmer Cc: freebsd-stable@freebsd.org Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20171231164738.GY1684@kib.kiev.ua> References: <20171231141708.GA2629@in-addr.com> <20171231145147.GW1684@kib.kiev.ua> <20171231154913.GA63310@in-addr.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20171231154913.GA63310@in-addr.com> User-Agent: Mutt/1.9.2 (2017-12-15) X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00, DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no autolearn_force=no version=3.4.1 X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on tom.home X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 31 Dec 2017 16:47:51 -0000 On Sun, Dec 31, 2017 at 03:49:13PM +0000, Gary Palmer wrote: > On Sun, Dec 31, 2017 at 04:51:47PM +0200, Konstantin Belousov wrote: > > On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > > > > > Hi, > > > > > > I recently updated to 11.1-RELEASE-p6 and on the most recent reboot > > > (after rebuilding all the necessary packages) the clock was running > > > slow and NTP wouldn't sync. I looked in /var/log/messages and I found > > > that for some reason, on this latest boot, it got the frequency of > > > TSC-low wrong. > > > > > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 Hz quality 1000 > > > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 Hz quality 1000 > > > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 Hz quality 1000 > > > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 Hz quality 1000 > > > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 Hz quality 1000 > > > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 Hz quality 1000 > > > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 Hz quality 1000 > > > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 Hz quality 1000 > > > > > > Until the December reboots the machine was running 10.x. Dec 27 and later > > > are part of the process to get up to 11.x. > > > > > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the last > > > measurement? > > > > > > I switched to HPET temporarily via sysctl and ntp seems happy. I'm just > > > concerned that the problem might recur on later reboots as TSC-low seems > > > to be the preferred timecounter. > > > > Show first 100 lines of the dmesg from a verbose boot. > > Also check BIOS settings related to overclocking and powersaving. > > > > Hi Konstantin, > > BIOS settings haven't been changed in 4+ years. No overclocking, and > all powersaving options are at "auto" or "disabled". > > The first 100 lines of verbose dmesg didn't seem that interesting so > I've included up to the end of "Device configuration finished" > > Note that this boot didn't have the TSC-low problem, and the boot > that had it wasn't verbose unfortunately. It is really the CPU identification which I wanted to see. You have IvyBridge, which is known to have good TSC. Try to obtain verbose dmesg with mis-identified frequency. From owner-freebsd-stable@freebsd.org Tue Jan 2 16:45:29 2018 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id A1975EAE5B6 for ; Tue, 2 Jan 2018 16:45:29 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from mail.in-addr.com (mail.in-addr.com [IPv6:2a01:4f8:191:61e8::2525:2525]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 6BBEB6887E for ; Tue, 2 Jan 2018 16:45:29 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from gjp by mail.in-addr.com with local (Exim 4.90 (FreeBSD)) (envelope-from ) id 1eWPgs-000Hgz-Gy; Tue, 02 Jan 2018 16:45:26 +0000 Date: Tue, 2 Jan 2018 16:45:26 +0000 From: Gary Palmer To: Konstantin Belousov Cc: freebsd-stable@freebsd.org Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20180102164526.GA63396@in-addr.com> References: <20171231141708.GA2629@in-addr.com> <20171231145147.GW1684@kib.kiev.ua> <20171231154913.GA63310@in-addr.com> <20171231164738.GY1684@kib.kiev.ua> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20171231164738.GY1684@kib.kiev.ua> X-SA-Exim-Connect-IP: X-SA-Exim-Mail-From: gpalmer@freebsd.org X-SA-Exim-Scanned: No (on mail.in-addr.com); SAEximRunCond expanded to false X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 02 Jan 2018 16:45:29 -0000 On Sun, Dec 31, 2017 at 06:47:38PM +0200, Konstantin Belousov wrote: > On Sun, Dec 31, 2017 at 03:49:13PM +0000, Gary Palmer wrote: > > On Sun, Dec 31, 2017 at 04:51:47PM +0200, Konstantin Belousov wrote: > > > On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > > > > > > > Hi, > > > > > > > > I recently updated to 11.1-RELEASE-p6 and on the most recent reboot > > > > (after rebuilding all the necessary packages) the clock was running > > > > slow and NTP wouldn't sync. I looked in /var/log/messages and I found > > > > that for some reason, on this latest boot, it got the frequency of > > > > TSC-low wrong. > > > > > > > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 Hz quality 1000 > > > > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 Hz quality 1000 > > > > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 Hz quality 1000 > > > > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 Hz quality 1000 > > > > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 Hz quality 1000 > > > > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 Hz quality 1000 > > > > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 Hz quality 1000 > > > > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 Hz quality 1000 > > > > > > > > Until the December reboots the machine was running 10.x. Dec 27 and later > > > > are part of the process to get up to 11.x. > > > > > > > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the last > > > > measurement? > > > > > > > > I switched to HPET temporarily via sysctl and ntp seems happy. I'm just > > > > concerned that the problem might recur on later reboots as TSC-low seems > > > > to be the preferred timecounter. > > > > > > Show first 100 lines of the dmesg from a verbose boot. > > > Also check BIOS settings related to overclocking and powersaving. > > > > > > > Hi Konstantin, > > > > BIOS settings haven't been changed in 4+ years. No overclocking, and > > all powersaving options are at "auto" or "disabled". > > > > The first 100 lines of verbose dmesg didn't seem that interesting so > > I've included up to the end of "Device configuration finished" > > > > Note that this boot didn't have the TSC-low problem, and the boot > > that had it wasn't verbose unfortunately. > > It is really the CPU identification which I wanted to see. You have > IvyBridge, which is known to have good TSC. Ah > Try to obtain verbose dmesg with mis-identified frequency. Tried, and failed after 20+ reboots. I've left boot_verbose=" -v" in /boot/loader.conf to catch any boot-time wonkiness and undone it at runtime with debug.bootverbose=0 in /etc/sysctl.conf as I found that the snd_hda driver is ... chatty at runtime. Thanks, Gary From owner-freebsd-stable@freebsd.org Tue Jan 2 22:41:38 2018 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id A5CFAEBD3FE for ; Tue, 2 Jan 2018 22:41:38 +0000 (UTC) (envelope-from bsd-lists@BSDforge.com) Received: from udns.ultimatedns.net (static-24-113-41-81.wavecable.com [24.113.41.81]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 8F65476B51; Tue, 2 Jan 2018 22:41:37 +0000 (UTC) (envelope-from bsd-lists@BSDforge.com) Received: from udns.ultimatedns.net (localhost [127.0.0.1]) by udns.ultimatedns.net (8.14.9/8.14.9) with ESMTP id w02MfV8l069712; Tue, 2 Jan 2018 14:41:37 -0800 (PST) (envelope-from bsd-lists@BSDforge.com) X-Mailer: UDNSMS MIME-Version: 1.0 Cc: , "Konstantin Belousov" In-Reply-To: <20180102164526.GA63396@in-addr.com> From: "Chris H" Reply-To: bsd-lists@BSDforge.com To: "Gary Palmer" Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Date: Tue, 02 Jan 2018 14:41:37 -0800 Message-Id: Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: quoted-printable X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 02 Jan 2018 22:41:38 -0000 On Tue, 2 Jan 2018 16:45:26 +0000 "Gary Palmer" said > On Sun, Dec 31, 2017 at 06:47:38PM +0200, Konstantin Belousov wrote: > > On Sun, Dec 31, 2017 at 03:49:13PM +0000, Gary Palmer wrote: > > > On Sun, Dec 31, 2017 at 04:51:47PM +0200, Konstantin Belousov wrote: > > > > On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > > > >=20 > > > > > Hi, > > > > >=20 > > > > > I recently updated to 11=2E1-RELEASE-p6 and on the most recent rebo= ot=20 > > > > > (after rebuilding all the necessary packages) the clock was runni= ng=20 > > > > > slow and NTP wouldn't sync=2E I looked in /var/log/messages and I = found > > > > > that for some reason, on this latest boot, it got the frequency o= f > > > > > TSC-low wrong=2E > > > > >=20 > > > > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 174607= 3190 > > Hz quality 1000 > > > > > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 174607= 0760 > > Hz quality 1000 > > > > > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 174607= 5204 > > Hz quality 1000 > > > > > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 174607= 0746 > > Hz quality 1000 > > > > > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 174607= 4808 > > Hz quality 1000 > > > > > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 174607= 1892 > > Hz quality 1000 > > > > > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 174606= 9704 > > Hz quality 1000 > > > > > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 193787= 6448 > > Hz quality 1000 > > > > >=20 > > > > > Until the December reboots the machine was running 10=2Ex=2E Dec 27 = and > > later > > > > > are part of the process to get up to 11=2Ex=2E > > > > >=20 > > > > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the la= st > > > > > measurement? > > > > >=20 > > > > > I switched to HPET temporarily via sysctl and ntp seems happy=2E I= 'm > > just > > > > > concerned that the problem might recur on later reboots as TSC-lo= w > > seems > > > > > to be the preferred timecounter=2E > > > >=20 > > > > Show first 100 lines of the dmesg from a verbose boot=2E > > > > Also check BIOS settings related to overclocking and powersaving=2E > > > >=20 > > >=20 > > > Hi Konstantin, > > >=20 > > > BIOS settings haven't been changed in 4+ years=2E No overclocking, and > > > all powersaving options are at "auto" or "disabled"=2E > > >=20 > > > The first 100 lines of verbose dmesg didn't seem that interesting so > > > I've included up to the end of "Device configuration finished" > > >=20 > > > Note that this boot didn't have the TSC-low problem, and the boot > > > that had it wasn't verbose unfortunately=2E > >=20 > > It is really the CPU identification which I wanted to see=2E You have > > IvyBridge, which is known to have good TSC=2E >=20 > Ah >=20 > > Try to obtain verbose dmesg with mis-identified frequency=2E >=20 > Tried, and failed after 20+ reboots=2E I've left >=20 > boot_verbose=3D" -v" I believe that should read: boot_verbose=3D"YES" but maybe just the occurrence of something makes it a positive=2E >=20 > in /boot/loader=2Econf to catch any boot-time wonkiness and undone it at > runtime with=20 >=20 > debug=2Ebootverbose=3D0 >=20 > in /etc/sysctl=2Econf as I found that the snd_hda driver is =2E=2E=2E chatty > at runtime=2E >=20 > Thanks, >=20 > Gary > _______________________________________________ > freebsd-stable@freebsd=2Eorg mailing list > https://lists=2Efreebsd=2Eorg/mailman/listinfo/freebsd-stable > To unsubscribe, send any mail to "freebsd-stable-unsubscribe@freebsd=2Eorg" From owner-freebsd-stable@freebsd.org Wed Jan 3 15:06:24 2018 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 1F360E8161B for ; Wed, 3 Jan 2018 15:06:24 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from mail.in-addr.com (mail.in-addr.com [IPv6:2a01:4f8:191:61e8::2525:2525]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id DFB527731C for ; Wed, 3 Jan 2018 15:06:23 +0000 (UTC) (envelope-from gpalmer@freebsd.org) Received: from gjp by mail.in-addr.com with local (Exim 4.90 (FreeBSD)) (envelope-from ) id 1eWkcW-000L29-IG; Wed, 03 Jan 2018 15:06:20 +0000 Date: Wed, 3 Jan 2018 15:06:20 +0000 From: Gary Palmer To: Chris H Cc: freebsd-stable@freebsd.org Subject: Re: Odd behaviour on recent boot of 11.1 with timecounters Message-ID: <20180103150620.GA80728@in-addr.com> References: <20180102164526.GA63396@in-addr.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: X-SA-Exim-Connect-IP: X-SA-Exim-Mail-From: gpalmer@freebsd.org X-SA-Exim-Scanned: No (on mail.in-addr.com); SAEximRunCond expanded to false X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 03 Jan 2018 15:06:24 -0000 On Tue, Jan 02, 2018 at 02:41:37PM -0800, Chris H wrote: > On Tue, 2 Jan 2018 16:45:26 +0000 "Gary Palmer" said > > > On Sun, Dec 31, 2017 at 06:47:38PM +0200, Konstantin Belousov wrote: > > > On Sun, Dec 31, 2017 at 03:49:13PM +0000, Gary Palmer wrote: > > > > On Sun, Dec 31, 2017 at 04:51:47PM +0200, Konstantin Belousov wrote: > > > > > On Sun, Dec 31, 2017 at 02:17:08PM +0000, Gary Palmer wrote: > > > > > > > > > > > > Hi, > > > > > > > > > > > > I recently updated to 11.1-RELEASE-p6 and on the most recent reboot > > > > > > (after rebuilding all the necessary packages) the clock was running > > > > > > slow and NTP wouldn't sync. I looked in /var/log/messages and I found > > > > > > that for some reason, on this latest boot, it got the frequency of > > > > > > TSC-low wrong. > > > > > > > > > > > > Aug 24 04:55:35 my kernel: Timecounter "TSC-low" frequency 1746073190 > > > Hz quality 1000 > > > > > > Aug 26 03:11:38 my kernel: Timecounter "TSC-low" frequency 1746070760 > > > Hz quality 1000 > > > > > > Aug 26 14:12:46 my kernel: Timecounter "TSC-low" frequency 1746075204 > > > Hz quality 1000 > > > > > > Nov 19 16:01:09 my kernel: Timecounter "TSC-low" frequency 1746070746 > > > Hz quality 1000 > > > > > > Dec 27 22:28:00 my kernel: Timecounter "TSC-low" frequency 1746074808 > > > Hz quality 1000 > > > > > > Dec 27 22:51:12 my kernel: Timecounter "TSC-low" frequency 1746071892 > > > Hz quality 1000 > > > > > > Dec 28 12:50:46 my kernel: Timecounter "TSC-low" frequency 1746069704 > > > Hz quality 1000 > > > > > > Dec 28 14:03:52 my kernel: Timecounter "TSC-low" frequency 1937876448 > > > Hz quality 1000 > > > > > > > > > > > > Until the December reboots the machine was running 10.x. Dec 27 and > > > later > > > > > > are part of the process to get up to 11.x. > > > > > > > > > > > > Any idea why the TSC-low frequency jumped 191,806,744Hz on the last > > > > > > measurement? > > > > > > > > > > > > I switched to HPET temporarily via sysctl and ntp seems happy. I'm > > > just > > > > > > concerned that the problem might recur on later reboots as TSC-low > > > seems > > > > > > to be the preferred timecounter. > > > > > > > > > > Show first 100 lines of the dmesg from a verbose boot. > > > > > Also check BIOS settings related to overclocking and powersaving. > > > > > > > > > > > > > Hi Konstantin, > > > > > > > > BIOS settings haven't been changed in 4+ years. No overclocking, and > > > > all powersaving options are at "auto" or "disabled". > > > > > > > > The first 100 lines of verbose dmesg didn't seem that interesting so > > > > I've included up to the end of "Device configuration finished" > > > > > > > > Note that this boot didn't have the TSC-low problem, and the boot > > > > that had it wasn't verbose unfortunately. > > > > > > It is really the CPU identification which I wanted to see. You have > > > IvyBridge, which is known to have good TSC. > > > > Ah > > > > > Try to obtain verbose dmesg with mis-identified frequency. > > > > Tried, and failed after 20+ reboots. I've left > > > > boot_verbose=" -v" > I believe that should read: > > boot_verbose="YES" > but maybe just the occurrence of something makes it a positive. Looks like you're right. I got confused by this comment in /boot/defaults/loader.conf #boot_verbose="" # -v: Causes extra debugging information to be printed After struggling with forth (which I haven't touched in a long time) it looks like it just tests for the existence of the variable, but whent he menu toggles verbose on it sets boot_verbose=YES Thanks for the hint Gary > > > > in /boot/loader.conf to catch any boot-time wonkiness and undone it at > > runtime with > > > > debug.bootverbose=0 > > > > in /etc/sysctl.conf as I found that the snd_hda driver is ... chatty > > at runtime. > > > > Thanks, > > > > Gary > > _______________________________________________ > > freebsd-stable@freebsd.org mailing list > > https://lists.freebsd.org/mailman/listinfo/freebsd-stable > > To unsubscribe, send any mail to "freebsd-stable-unsubscribe@freebsd.org" > > > From owner-freebsd-stable@freebsd.org Thu Jan 4 02:51:23 2018 Return-Path: Delivered-To: freebsd-stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 3628BEC0B9A for ; Thu, 4 Jan 2018 02:51:23 +0000 (UTC) (envelope-from shen.elf@gmail.com) Received: from mailman.ysv.freebsd.org (mailman.ysv.freebsd.org [IPv6:2001:1900:2254:206a::50:5]) by mx1.freebsd.org (Postfix) with ESMTP id 1162F753EB for ; Thu, 4 Jan 2018 02:51:23 +0000 (UTC) (envelope-from shen.elf@gmail.com) Received: by mailman.ysv.freebsd.org (Postfix) id 10BEBEC0B99; Thu, 4 Jan 2018 02:51:23 +0000 (UTC) Delivered-To: stable@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 105BBEC0B98 for ; Thu, 4 Jan 2018 02:51:23 +0000 (UTC) (envelope-from shen.elf@gmail.com) Received: from mail-io0-x233.google.com (mail-io0-x233.google.com [IPv6:2607:f8b0:4001:c06::233]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id D9B1A753E9 for ; Thu, 4 Jan 2018 02:51:22 +0000 (UTC) (envelope-from shen.elf@gmail.com) Received: by mail-io0-x233.google.com with SMTP id x67so714407ioi.9 for ; Wed, 03 Jan 2018 18:51:22 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:in-reply-to:references:from:date:message-id:subject:cc; bh=m/VlYpqnWB9KuGZd9dooti/wed9y9S7lMHyKgKl3Tbk=; b=ekNMHDwbFgoveo0KhIADLnGfLwMu2Rl+LidAODMYSpBCdLusjyUVBp/+m34Ja6h4bJ 6l4Y9YfHDNn3STyFU4W4g2eoajO3pqP0aZ8Eqw5Uc6ucshl3A6Jyq8u3Zbm7NyVBEwyr 7K/Jnugt+1ky4azbrQjoaOnaA78Olpx8M/Ssp0g1LYz3jbV9QKWVCKHTE9aS7nJ++UFw DM+79009tqXjf7iS5WCw8rPOn2DsMSEb23qLMBEyI59HFRA8UauRaqMAseZuonH9IXOi +nOgTHwJES+6Y/Fga4nM11rL/wGzw5NoVvg1JL03OeDhudC6hWvsUC/ftMpLvcwmxfv4 F/Yw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:in-reply-to:references:from:date :message-id:subject:cc; bh=m/VlYpqnWB9KuGZd9dooti/wed9y9S7lMHyKgKl3Tbk=; b=ehuIAW2LeBUs27Rw/NV2G+dhxDt9z80w89l6I2SKcL/9uzv5vVqbG0hRAd/w3Fbnbr HF1n89PBTGYSA94B61OFiackkAWPooRo1tZxZbTTw3kODtIkjoRN0ZXGWHx9a8Z/NS1H jY7e6XW3fuDzPsJ+zQ3KMSr7/uyxD7/ecy2DGr5QNfMzy97mV3ZItqp7eTS9BF2kk0pt Myfe1vzXSNFZvKJ9QyUXL6fJdC2cIjP/7051BfybjsTDSUFyDx10FwaBZO9fL6mYR8No 59l1htZRSzk0I1yPJLCH60goenNEam+eTXzKs/pu7TThjtHJoWXhQPXH3DXXYMTr+oIC 05lw== X-Gm-Message-State: AKGB3mJ0Dx/yHa199o4N6I+GGtEa0XUuianuK0j2IHAuxoQobvPU6CDw t7gRW3vEI2s4qFK3xVLhtyN7x0Uclq7kz8l43s5pXg== X-Google-Smtp-Source: ACJfBosrHfbFK0dteXvCL709YxCFxy5odD2Ak/wOmOK4rxaEeYaaJY6Y9meKulLqeCISD0UV5GROkRhE2dGsmbPO9bQ= X-Received: by 10.107.162.205 with SMTP id l196mr3826148ioe.185.1515034282046; Wed, 03 Jan 2018 18:51:22 -0800 (PST) MIME-Version: 1.0 Received: by 10.2.86.11 with HTTP; Wed, 3 Jan 2018 18:50:41 -0800 (PST) In-Reply-To: <20161017143416.14024482@fabiankeil.de> References: <20161017143416.14024482@fabiankeil.de> From: Yanhui Shen Date: Thu, 4 Jan 2018 10:50:41 +0800 Message-ID: Subject: Re: Poor ZFS ARC metadata hit/miss stats after recent ZFS updates Cc: stable@freebsd.org Content-Type: text/plain; charset="UTF-8" X-Content-Filtered-By: Mailman/MimeDel 2.1.25 X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 04 Jan 2018 02:51:23 -0000 This link might be helpful: "Bug 222929 - ZFS ARC stats have wrong count" https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=222929 Best regards, Yanhui Shen 2016-10-17 20:34 GMT+08:00 Fabian Keil : > After rebasing some of my systems from r305866 to r307312 > (plus local patches) I noticed that most of the ARC accesses > are counted as misses now. > > Example: > > [fk@elektrobier2 ~]$ uptime > 2:03PM up 1 day, 18:36, 7 users, load averages: 0.29, 0.36, 0.30 > [fk@elektrobier2 ~]$ zfs-stats -E > > ------------------------------------------------------------------------ > ZFS Subsystem Report Mon Oct 17 14:03:58 2016 > ------------------------------------------------------------------------ > > ARC Efficiency: 3.38m > Cache Hit Ratio: 12.87% 435.23k > Cache Miss Ratio: 87.13% 2.95m > Actual Hit Ratio: 9.55% 323.15k > > Data Demand Efficiency: 6.61% 863.01k > > CACHE HITS BY CACHE LIST: > Most Recently Used: 18.97% 82.54k > Most Frequently Used: 55.28% 240.60k > Most Recently Used Ghost: 8.88% 38.63k > Most Frequently Used Ghost: 24.84% 108.12k > > CACHE HITS BY DATA TYPE: > Demand Data: 13.10% 57.03k > Prefetch Data: 0.00% 0 > Demand Metadata: 32.94% 143.36k > Prefetch Metadata: 53.96% 234.85k > > CACHE MISSES BY DATA TYPE: > Demand Data: 27.35% 805.98k > Prefetch Data: 0.00% 0 > Demand Metadata: 71.21% 2.10m > Prefetch Metadata: 1.44% 42.48k > > ------------------------------------------------------------------------ > > I suspect that this is caused by r307265 ("MFC r305323: MFV r302991: > 6950 ARC should cache compressed data") which removed a > ARCSTAT_CONDSTAT() call but I haven't confirmed this yet. > > The system performance doesn't actually seem to be negatively affected > and repeated metadata accesses that are counted as misses are still served > from memory. On my freshly booted laptop I get: > > fk@t520 /usr/ports $for i in 1 2 3; do \ > /usr/local/etc/munin/plugins/zfs-absolute-arc-hits-and-misses; \ > time git status > /dev/null; \ > done; \ > /usr/local/etc/munin/plugins/zfs-absolute-arc-hits-and-misses; > zfs_arc_hits.value 5758 > zfs_arc_misses.value 275416 > zfs_arc_demand_metadata_hits.value 4331 > zfs_arc_demand_metadata_misses.value 270252 > zfs_arc_demand_data_hits.value 304 > zfs_arc_demand_data_misses.value 3345 > zfs_arc_prefetch_metadata_hits.value 1103 > zfs_arc_prefetch_metadata_misses.value 1489 > zfs_arc_prefetch_data_hits.value 20 > zfs_arc_prefetch_data_misses.value 334 > > real 1m23.398s > user 0m0.974s > sys 0m12.273s > zfs_arc_hits.value 11346 > zfs_arc_misses.value 389748 > zfs_arc_demand_metadata_hits.value 7723 > zfs_arc_demand_metadata_misses.value 381018 > zfs_arc_demand_data_hits.value 400 > zfs_arc_demand_data_misses.value 3412 > zfs_arc_prefetch_metadata_hits.value 3202 > zfs_arc_prefetch_metadata_misses.value 4885 > zfs_arc_prefetch_data_hits.value 21 > zfs_arc_prefetch_data_misses.value 437 > > real 0m1.472s > user 0m0.452s > sys 0m1.820s > zfs_arc_hits.value 11348 > zfs_arc_misses.value 428536 > zfs_arc_demand_metadata_hits.value 7723 > zfs_arc_demand_metadata_misses.value 419782 > zfs_arc_demand_data_hits.value 400 > zfs_arc_demand_data_misses.value 3436 > zfs_arc_prefetch_metadata_hits.value 3204 > zfs_arc_prefetch_metadata_misses.value 4885 > zfs_arc_prefetch_data_hits.value 21 > zfs_arc_prefetch_data_misses.value 437 > > real 0m1.537s > user 0m0.461s > sys 0m1.860s > zfs_arc_hits.value 11352 > zfs_arc_misses.value 467334 > zfs_arc_demand_metadata_hits.value 7723 > zfs_arc_demand_metadata_misses.value 458556 > zfs_arc_demand_data_hits.value 400 > zfs_arc_demand_data_misses.value 3460 > zfs_arc_prefetch_metadata_hits.value 3208 > zfs_arc_prefetch_metadata_misses.value 4885 > zfs_arc_prefetch_data_hits.value 21 > zfs_arc_prefetch_data_misses.value 437 > > Disabling ARC compression through vfs.zfs.compressed_arc_enabled > does not affect the accounting issue. > > Can anybody reproduce this? > > Fabian >