Re: Waiting for bufdaemon

On 15/01/2021 17:35, Konstantin Belousov wrote:
> 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).
> 
Thanks, I've updated the file on freefall