Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

[Ben Hutchings]

[-- Attachment #1: Type: text/plain, Size: 3472 bytes --]

On Wed, 2017-02-15 at 09:08 +0100, Miloslav Hula wrote:
[...]
> When I boot the system up, there is a constant load 1.0. I found one
> process systemd-udevd in uninterruptible sleep.
> Digging in proc/PID/fd I found, this proces usees fd 7 for
> intel_rapl_perf.ko
> 
> * What exactly did you do (or not do) that was effective (or
> ineffective)?
> I rmmod intel_rapl_perf, the systemd-udevd process disappeared. I
> tried to load intel_rapl_perf manually.
> 
> * What was the outcome of this action?
> Now, the modprobe is in uninterruptible sleep
[...]

Here's a traceback for that:

> [ 1090.784109] INFO: task systemd-udevd:1182 blocked for more than 120 seconds.
> [ 1090.784167]       Not tainted 4.9.0-0.bpo.1-amd64 #1
> [ 1090.784202] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 1090.784254] systemd-udevd   D    0  1182   1098 0x00000004
> [ 1090.784260]  ffffa079b6c9d000 0000000000000000 ffffa089b8ffa0c0 ffffa079b688c140
> [ 1090.784265]  ffffa089bf2987c0 ffffc1d3ce12bb30 ffffffff929f536d ffffa089bf3d8828
> [ 1090.784268]  ffffc1d3ce12bb60 00000000924b0afe ffffa089bf2987c0 ffffa079b688c140
> [ 1090.784272] Call Trace:
> [ 1090.784284]  [<ffffffff929f536d>] ? __schedule+0x23d/0x6d0
> [ 1090.784308]  [<ffffffffc083e6b0>] ? uncore_cpu_prepare+0x100/0x100 [intel_uncore]
> [ 1090.784310]  [<ffffffff929f5832>] ? schedule+0x32/0x80
> [ 1090.784316]  [<ffffffff929f8d3c>] ? schedule_timeout+0x21c/0x3c0
> [ 1090.784327]  [<ffffffff924b1374>] ? enqueue_task_fair+0x74/0x950
> [ 1090.784329]  [<ffffffff929f5375>] ? __schedule+0x245/0x6d0
> [ 1090.784336]  [<ffffffff9242ed05>] ? sched_clock+0x5/0x10
> [ 1090.784344]  [<ffffffffc083e6b0>] ? uncore_cpu_prepare+0x100/0x100 [intel_uncore]
> [ 1090.784347]  [<ffffffff929f624a>] ? wait_for_completion+0xfa/0x130
> [ 1090.784353]  [<ffffffff924a2b60>] ? wake_up_q+0x60/0x60
> [ 1090.784358]  [<ffffffff924791b6>] ? cpuhp_issue_call+0x96/0xc0
> [ 1090.784361]  [<ffffffff9247946a>] ? __cpuhp_setup_state+0xca/0x200
> [ 1090.784369]  [<ffffffffc069d34d>] ? intel_uncore_init+0x1f7/0xeaa [intel_uncore]
> [ 1090.784376]  [<ffffffffc069d156>] ? uncore_type_init+0x156/0x156 [intel_uncore]
> [ 1090.784383]  [<ffffffff9240218c>] ? do_one_initcall+0x4c/0x180
> [ 1090.784393]  [<ffffffff9257cbaf>] ? do_init_module+0x5a/0x1f1
> [ 1090.784400]  [<ffffffff92502729>] ? load_module+0x23c9/0x28f0
> [ 1090.784403]  [<ffffffff924fef90>] ? __symbol_put+0x60/0x60
> [ 1090.784411]  [<ffffffff92603964>] ? vfs_read+0x114/0x130
> [ 1090.784418]  [<ffffffff926a4351>] ? security_capable+0x41/0x60
> [ 1090.784421]  [<ffffffff92502e3e>] ? SYSC_finit_module+0x8e/0xe0
> [ 1090.784425]  [<ffffffff929fa1bb>] ? system_call_fast_compare_end+0xc/0x9b
[...]

The CPU is a Broadwell (I don't have more information than that);
here's the model information from DMI:

> ** Model information
> sys_vendor: Supermicro
> product_name: X10DRi
> product_version: 123456789
> chassis_vendor: Default string
> chassis_version: Default string
> bios_vendor: American Megatrends Inc.
> bios_version: 2.1
> board_vendor: Supermicro
> board_name: X10DRi
> board_version: 1.02B
[...]

The full bug report is at <https://bugs.debian.org/855183>, with a
little more system information.

Ben.

-- 
Ben Hutchings
Any sufficiently advanced bug is indistinguishable from a feature.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

[Thomas Gleixner]

[-- Attachment #1: Type: text/plain, Size: 2589 bytes --]

On Fri, 17 Feb 2017, Ben Hutchings wrote:
> On Wed, 2017-02-15 at 09:08 +0100, Miloslav Hula wrote:
> [...]
> > When I boot the system up, there is a constant load 1.0. I found one
> > process systemd-udevd in uninterruptible sleep.
> > Digging in proc/PID/fd I found, this proces usees fd 7 for
> > intel_rapl_perf.ko
> > 
> > * What exactly did you do (or not do) that was effective (or
> > ineffective)?
> > I rmmod intel_rapl_perf, the systemd-udevd process disappeared. I
> > tried to load intel_rapl_perf manually.
> > 
> > * What was the outcome of this action?
> > Now, the modprobe is in uninterruptible sleep
> [...]
> 
> Here's a traceback for that:
> 
> > [ 1090.784260]  ffffa079b6c9d000 0000000000000000 ffffa089b8ffa0c0 ffffa079b688c140
> > [ 1090.784265]  ffffa089bf2987c0 ffffc1d3ce12bb30 ffffffff929f536d ffffa089bf3d8828
> > [ 1090.784268]  ffffc1d3ce12bb60 00000000924b0afe ffffa089bf2987c0 ffffa079b688c140
> > [ 1090.784272] Call Trace:
> > [ 1090.784284]  [<ffffffff929f536d>] ? __schedule+0x23d/0x6d0
> > [ 1090.784308]  [<ffffffffc083e6b0>] ? uncore_cpu_prepare+0x100/0x100 [intel_uncore]
> > [ 1090.784310]  [<ffffffff929f5832>] ? schedule+0x32/0x80
> > [ 1090.784316]  [<ffffffff929f8d3c>] ? schedule_timeout+0x21c/0x3c0
> > [ 1090.784327]  [<ffffffff924b1374>] ? enqueue_task_fair+0x74/0x950
> > [ 1090.784329]  [<ffffffff929f5375>] ? __schedule+0x245/0x6d0
> > [ 1090.784336]  [<ffffffff9242ed05>] ? sched_clock+0x5/0x10
> > [ 1090.784344]  [<ffffffffc083e6b0>] ? uncore_cpu_prepare+0x100/0x100 [intel_uncore]
> > [ 1090.784347]  [<ffffffff929f624a>] ? wait_for_completion+0xfa/0x130
> > [ 1090.784353]  [<ffffffff924a2b60>] ? wake_up_q+0x60/0x60
> > [ 1090.784358]  [<ffffffff924791b6>] ? cpuhp_issue_call+0x96/0xc0
> > [ 1090.784361]  [<ffffffff9247946a>] ? __cpuhp_setup_state+0xca/0x200
> > [ 1090.784369]  [<ffffffffc069d34d>] ? intel_uncore_init+0x1f7/0xeaa [intel_uncore]

Unfortunately that tells us only that something waits forever, but we don't
see the stuff which does not invoke complete().

AFAICT thats a cpuhp thread which should run the cpu starting or online
callback.

What's really confusing is this information from the bug report:

" When I changed:

  Power technology:
  - from Energy Efficient
  - to Custom

  Energy Performance BIAS Setting:
  - from Balanced Performance
  - to Performance

  problem disappeared. systemd-udevd starts normally, module can be 
  normally rmmod/insmod'ed now, load is 0.07."

Miloslav: Is there any chance you can try a 4.10-rc8 kernel on that
machine?

Thanks,

	tglx

Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

[Miloslav Hůla]

Dne 17.02.2017 v 11:47 Thomas Gleixner napsal(a):
> What's really confusing is this information from the bug report:
>
> " When I changed:
>
>   Power technology:
>   - from Energy Efficient
>   - to Custom
>
>   Energy Performance BIAS Setting:
>   - from Balanced Performance
>   - to Performance
>
>   problem disappeared. systemd-udevd starts normally, module can be
>   normally rmmod/insmod'ed now, load is 0.07."
>
> Miloslav: Is there any chance you can try a 4.10-rc8 kernel on that
> machine?

I compiled 4.10-rc8 kernel with a stock 
'/boot/config-4.9.0-0.bpo.1-amd64' config from Debian Jessie backports. 
Then I reverted BIOS settings to previous state and rebooted the server. 
Kernel and all modules loaded normally, rmmod/insmod intel_rapl_perf 
passed normally.

Then, without any BIOS change, I rebooted with stock 4.9.0-0.bpo.1-amd64 
and suprisingly, everything works, I cannot reproduce it.

My knowledge on the field of BIOS are shallow. I don't know what I can 
do to reproduce the bug now.

King redards, Miloslav

Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

[Thomas Gleixner]

[-- Attachment #1: Type: text/plain, Size: 1208 bytes --]

On Mon, 20 Feb 2017, Miloslav Hůla wrote:
> Dne 17.02.2017 v 11:47 Thomas Gleixner napsal(a):
> > What's really confusing is this information from the bug report:
> > 
> > " When I changed:
> > 
> >   Power technology:
> >   - from Energy Efficient
> >   - to Custom
> > 
> >   Energy Performance BIAS Setting:
> >   - from Balanced Performance
> >   - to Performance
> > 
> >   problem disappeared. systemd-udevd starts normally, module can be
> >   normally rmmod/insmod'ed now, load is 0.07."
> > 
> > Miloslav: Is there any chance you can try a 4.10-rc8 kernel on that
> > machine?
> 
> I compiled 4.10-rc8 kernel with a stock '/boot/config-4.9.0-0.bpo.1-amd64'
> config from Debian Jessie backports. Then I reverted BIOS settings to previous
> state and rebooted the server. Kernel and all modules loaded normally,
> rmmod/insmod intel_rapl_perf passed normally.
> 
> Then, without any BIOS change, I rebooted with stock 4.9.0-0.bpo.1-amd64 and
> suprisingly, everything works, I cannot reproduce it.
> 
> My knowledge on the field of BIOS are shallow. I don't know what I can do to
> reproduce the bug now.

Did you just reboot or go through a cold start? That might make a difference.

Thanks,

	tglx

Re: Bug#855183: linux-image-4.9.0-0.bpo.1-amd64: modprobe intel_rapl_perf stay in uninterruptible sleep

[Miloslav Hůla]

Dne 21.02.2017 v 0:24 Thomas Gleixner napsal(a):
> On Mon, 20 Feb 2017, Miloslav Hůla wrote:
>> Dne 17.02.2017 v 11:47 Thomas Gleixner napsal(a):
>>> What's really confusing is this information from the bug report:
>>>
>>> " When I changed:
>>>
>>>   Power technology:
>>>   - from Energy Efficient
>>>   - to Custom
>>>
>>>   Energy Performance BIAS Setting:
>>>   - from Balanced Performance
>>>   - to Performance
>>>
>>>   problem disappeared. systemd-udevd starts normally, module can be
>>>   normally rmmod/insmod'ed now, load is 0.07."
>>>
>>> Miloslav: Is there any chance you can try a 4.10-rc8 kernel on that
>>> machine?
>>
>> I compiled 4.10-rc8 kernel with a stock '/boot/config-4.9.0-0.bpo.1-amd64'
>> config from Debian Jessie backports. Then I reverted BIOS settings to previous
>> state and rebooted the server. Kernel and all modules loaded normally,
>> rmmod/insmod intel_rapl_perf passed normally.
>>
>> Then, without any BIOS change, I rebooted with stock 4.9.0-0.bpo.1-amd64 and
>> suprisingly, everything works, I cannot reproduce it.
>>
>> My knowledge on the field of BIOS are shallow. I don't know what I can do to
>> reproduce the bug now.
>
> Did you just reboot or go through a cold start? That might make a difference.

Reboot only. I'll test it again in next maintenance window.

Regards, Milo