Re: Waiting for bufdaemon

On Fri, Jan 15, 2021 at 05:18:56PM +0100, Mikaël Urankar wrote:
> On 15/01/2021 16:45, Konstantin Belousov wrote:
> > On Fri, Jan 15, 2021 at 04:30:19PM +0100, Mikaël Urankar wrote:
> > > On 15/01/2021 16:02, Konstantin Belousov wrote:
> > > > On Fri, Jan 15, 2021 at 03:56:01PM +0100, Mikaël Urankar wrote:
> > > > > On 15/01/2021 11:26, Jakob Alvermark wrote:
> > > > > > Hi,
> > > > > > 
> > > > > > 
> > > > > > When rebooting my thinkpad the 'bufdaemon' times out:
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufdaemon' to stop ... timed
> > > > > > out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-0' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-1' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-2' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-3' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-4' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > Waiting (max 60 seconds) for system thread 'bufspacedaemon-5' to stop
> > > > > > ... timed out
> > > > > > 
> > > > > > 
> > > > > > This started happening recently (within the last week I think).
> > > > > 
> > > > > Hi,
> > > > > 
> > > > > I'm also affected. I have an AMD Ryzen 9 3900X cpu, running bare metal.
> > > > > 
> > > > > 5844bd058aed6f3d0c8cbbddd6aa95993ece0189 (jobc: rework detection of orphaned
> > > > > groups) "seems" ok
> > > > > 
> > > > > cd240c9cf100bec3def38ceb4a320611b1d02693 (x86 vdso gettc: Add RDTSCP
> > > > > support), affected by the timeout.
> > > > > 
> > > > > I haven't tried the intermediate commit yet.
> > > > > 
> > > > > My intel machine doesn't seem to be affected
> > > > 
> > > > If you revert only 9e680e4005b7, is it fixed ?
> > > > 
> > > Yes it seems to be fixed with 9e680e4005b7 reverted (I've only done 2 tests,
> > > I can do more if you want)
> > Please show me the output from sysctl
> > kern.timecounter
> > kern.eventtimer
> > and first 100 lines of dmesg from the verbose boot (that contains the CPU
> > ident lines).
> > 
> 
> I put the /var/run/dmesg.boot file on freefall /home/mikael/dmesg.boot (it
> seems to be truncated though, I don't know how to retrieve the full log)
> 
> sysctl kern.timecounter
> kern.timecounter.tsc_shift: 1
> kern.timecounter.smp_tsc_adjust: 0
> kern.timecounter.smp_tsc: 1
> kern.timecounter.invariant_tsc: 1
> kern.timecounter.fast_gettime: 1
> kern.timecounter.tick: 1
> kern.timecounter.choice: ACPI-fast(900) HPET(950) i8254(0) TSC-low(1000)
> dummy(-1000000)
> kern.timecounter.hardware: TSC-low
> kern.timecounter.alloweddeviation: 5
> kern.timecounter.timehands_count: 2
> kern.timecounter.stepwarnings: 0
> kern.timecounter.tc.ACPI-fast.quality: 900
> kern.timecounter.tc.ACPI-fast.frequency: 3579545
> kern.timecounter.tc.ACPI-fast.counter: 1470549582
> kern.timecounter.tc.ACPI-fast.mask: 4294967295
> kern.timecounter.tc.HPET.quality: 950
> kern.timecounter.tc.HPET.frequency: 14318180
> kern.timecounter.tc.HPET.counter: 378058131
> kern.timecounter.tc.HPET.mask: 4294967295
> kern.timecounter.tc.i8254.quality: 0
> kern.timecounter.tc.i8254.frequency: 1193182
> kern.timecounter.tc.i8254.counter: 20425
> kern.timecounter.tc.i8254.mask: 65535
> kern.timecounter.tc.TSC-low.quality: 1000
> kern.timecounter.tc.TSC-low.frequency: 1900039387
> kern.timecounter.tc.TSC-low.counter: 2386729797
> kern.timecounter.tc.TSC-low.mask: 4294967295
> 
> sysctl kern.eventtimer
> kern.eventtimer.choice: LAPIC(600) HPET(350) HPET1(350) HPET2(350)
> i8254(100) RTC(0)
> kern.eventtimer.et.HPET2.quality: 350
> kern.eventtimer.et.HPET2.frequency: 14318180
> kern.eventtimer.et.HPET2.flags: 3
> kern.eventtimer.et.HPET1.quality: 350
> kern.eventtimer.et.HPET1.frequency: 14318180
> kern.eventtimer.et.HPET1.flags: 3
> kern.eventtimer.et.HPET.quality: 350
> kern.eventtimer.et.HPET.frequency: 14318180
> kern.eventtimer.et.HPET.flags: 3
> kern.eventtimer.et.RTC.quality: 0
> kern.eventtimer.et.RTC.frequency: 32768
> kern.eventtimer.et.RTC.flags: 17
> kern.eventtimer.et.i8254.quality: 100
> kern.eventtimer.et.i8254.frequency: 1193182
> kern.eventtimer.et.i8254.flags: 1
> kern.eventtimer.et.LAPIC.quality: 600
> kern.eventtimer.et.LAPIC.frequency: 50001034
> kern.eventtimer.et.LAPIC.flags: 7
> kern.eventtimer.periodic: 0
> kern.eventtimer.timer: LAPIC
> kern.eventtimer.idletick: 0
> kern.eventtimer.singlemul: 2

It is clipped at the start, and that was the information which I need.
Add something like
kern.msgbufsize=1048576
to /boot/loader.conf and try again.  I need to see the lines starting with

CPU: Intel(R) Core(TM) i7-8550U CPU _at_ 1.80GHz (1992.08-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x806ea  Family=0x6  Model=0x8e  Stepping=10
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,C
MOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
...

(well, this is my w/s, your CPU would be different of course).