Re: Linux 4.9.6 ( Restore IO-APIC irq_chip retrigger callback , breaks my box )

[Gabriel C]

On 13.02.2017 01:38, Borislav Petkov wrote:
> On Sun, Feb 12, 2017 at 11:21:13PM +0100, Gabriel C wrote:
> > http://ftp.frugalware.org/pub/other/people/crazy/kernel/t/crash_initcall_debug.mp4
> > http://ftp.frugalware.org/pub/other/people/crazy/kernel/t/crash_intcall_debug_ucode_off.mp4
>
> Thanks and interesting. In both cases, mcheck_init_device() doesn't
> return or we don't see the "initcall returned" message.
>
> Ok, let's try a silly sprinkling of printks in that function and try to
> pinpoint how far we manage to come.
>
> Apply, build, boot and shoot video again :-)

I didn't tested your patch yet but did a boot with mce=off and nomce which seems to not
really works since is still want to mc_device_add() even when off.

See :


http://ftp.frugalware.org/pub/other/people/crazy/kernel/t/crash_mce_off.jpg

I'll build an .10-rc8 with your patch tomorrow .. is somewhat late now here :)


Another thing is .. there seems to be a real bug in tsc code .

I've build an -rc8 with a lot more debug options on an now I see the following :

...

[    4.321029] =================================
[    4.321909] [ INFO: inconsistent lock state ]
[    4.322789] 4.10.0-rc8-debug #1 Tainted: G          I
[    4.323879] ---------------------------------
[    4.324759] inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
[    4.325973] cpuhp/0/14 [HC0[0]:SC0[0]:HE1:SE1] takes:
[    4.326993]  (tick_broadcast_lock){?.....}, at: [<ffffffff810f40e7>] tick_broadcast_control+0x57/0x190
[    4.328879] {IN-HARDIRQ-W} state was registered at:
[    4.329866]   __lock_acquire+0x24f/0x19e0
[    4.330675]   lock_acquire+0xa5/0xd0
[    4.331399]   _raw_spin_lock_irqsave+0x54/0x90
[    4.332297]   tick_broadcast_switch_to_oneshot+0x11/0x50
[    4.333371]   tick_switch_to_oneshot+0x8c/0xd0
[    4.334269]   tick_init_highres+0x10/0x20
[    4.335079]   hrtimer_run_queues+0x5a/0xe0
[    4.335907]   run_local_timers+0x20/0x50
[    4.336699]   update_process_times+0x22/0x50
[    4.337562]   tick_periodic+0xa5/0xb0
[    4.338302]   tick_handle_periodic+0x1f/0x60
[    4.378065]   smp_trace_apic_timer_interrupt+0x74/0x90
[    4.418107]   smp_apic_timer_interrupt+0x9/0x10
[    4.458095]   apic_timer_interrupt+0x93/0xa0
[    4.498048]   mwait_idle+0x5a/0x90
[    4.537618]   arch_cpu_idle+0xa/0x10
[    4.577098]   default_idle_call+0x2c/0x30
[    4.616211]   do_idle+0x10c/0x1e0
[    4.654606]   cpu_startup_entry+0x5d/0x60
[    4.692388]   rest_init+0x12c/0x140
[    4.729557]   start_kernel+0x45f/0x46c
[    4.766325]   x86_64_start_reservations+0x2a/0x2c
[    4.803075]   x86_64_start_kernel+0xeb/0xf8
[    4.839178]   verify_cpu+0x0/0xfc
[    4.874629] irq event stamp: 71
[    4.909417] hardirqs last  enabled at (71): [<ffffffff8176a887>] _raw_spin_unlock_irq+0x27/0x50
[    4.945642] hardirqs last disabled at (70): [<ffffffff81762eaa>] __schedule+0x13a/0x7c0
[    4.981797] softirqs last  enabled at (0): [<ffffffff81060ef0>] copy_process+0x7c0/0x1ea0
[    5.018580] softirqs last disabled at (0): [<          (null)>]           (null)
[    5.055677]
               other info that might help us debug this:
[    5.072455] tsc: Refined TSC clocksource calibration: 2266.746 MHz
[    5.072467] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x20ac7f6ecc6, max_idle_ns: 440795315461 ns
[    5.202828]  Possible unsafe locking scenario:


^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

This seems to be the place where the other patch breaks hell here..


[    5.276704]        CPU0
[    5.312400]        ----
[    5.347605]   lock(tick_broadcast_lock);
[    5.383163]   <Interrupt>
[    5.418457]     lock(tick_broadcast_lock);
[    5.454015]
                *** DEADLOCK ***

[    5.557982] no locks held by cpuhp/0/14.
[    5.592295]
               stack backtrace:
[    5.657946] CPU: 0 PID: 14 Comm: cpuhp/0 Tainted: G          I     4.10.0-rc8-debug #1
[    5.690740] Hardware name: FUJITSU                          PRIMERGY TX200 S5             /D2709, BIOS 6.00 Rev. 1.14.2709              02/04/2013
[    5.758323] Call Trace:
[    5.791434]  dump_stack+0x86/0xc1
[    5.824421]  print_usage_bug+0x283/0x2a0
[    5.857357]  mark_lock+0x39e/0x650
[    5.890256]  ? check_usage_forwards+0xf0/0xf0
[    5.923436]  __lock_acquire+0x2ba/0x19e0
[    5.956617]  ? pick_next_task_fair+0x350/0x700
[    5.989903]  ? finish_task_switch+0x184/0x220
[    6.023171]  ? debug_smp_processor_id+0x17/0x20
[    6.056667]  lock_acquire+0xa5/0xd0
[    6.089882]  ? tick_broadcast_control+0x57/0x190
[    6.123395]  ? smpboot_thread_fn+0x28/0x250
[    6.156838]  _raw_spin_lock+0x3c/0x80
[    6.190175]  ? tick_broadcast_control+0x57/0x190
[    6.223914]  tick_broadcast_control+0x57/0x190
[    6.257846]  ? finish_task_switch+0x184/0x220
[    6.291900]  ? smpboot_thread_fn+0x28/0x250
[    6.325991]  intel_idle_cpu_online+0x1d/0x100
[    6.360220]  cpuhp_invoke_callback+0x62/0x120
[    6.394397]  ? smpboot_thread_fn+0x28/0x250
[    6.428451]  cpuhp_thread_fun+0x87/0x110
[    6.462611]  smpboot_thread_fn+0x227/0x250
[    6.496805]  kthread+0x125/0x130
[    6.530947]  ? sort_range+0x20/0x20
[    6.564126]  ? kthread_stop+0x70/0x70
[    6.597078]  ret_from_fork+0x31/0x40
[    6.630787] clocksource: Switched to clocksource tsc

...


Maybe Thomas has some ideas ?


Regards,

Gabriel C