Re: [Intel-gfx] 4.10-rc2 oops in DRM connector code

[Daniel Vetter]

On Mon, Jan 09, 2017 at 09:42:22AM -0800, Dave Hansen wrote:
> On 01/09/2017 08:59 AM, Daniel Vetter wrote:
> > On Mon, Jan 9, 2017 at 5:50 PM, Dave Hansen <dave.hansen@xxxxxxxxx> wrote:
> >> On 01/09/2017 08:41 AM, Daniel Vetter wrote:
> >>> On Mon, Jan 9, 2017 at 2:40 PM, Dave Hansen <dave.hansen@xxxxxxxxx> wrote:
> >>>> Well, now I found where the -2 comes from.
> >>>> intel_dp_register_mst_connector() calls drm_connector_register(), which
> >>>> fails to add the kobject (warning below).  But, it does zero error
> >>>> checking on the drm_connector_register() call and leaves the
> >>>> partially-constructed connector in place.
> >>>>
> >>>> The next time some poor, hapless code goes and tries to do anything with
> >>>> that kdev, they oops.  I'm perplexed by this, though.  The
> >>>> drm_dp_mst_topology_cbs->register_connector just returns void.  It seems
> >>>> a bit goofy that it can't even _return_ failure.
> >>>>
> >>>> Is there some stable code to go back to here?  Or, is there something
> >>>> about my configuration that's unique?  I really wonder why nobody else
> >>>> is running into this.
> >>>>
> >>>> There's probably some other race going on here.  This warning doesn't
> >>>> happen on every boot.
> >>> This smells more like the root-cause: Something goes wrong on boot
> >>> that prevents connectors from properly registering, then we fall over
> >>> later on. And the register callback is intentionally void, assuming
> >>> that any prep work has been done earlier and that therefore the
> >>> register step can't fail. Can you pls check whether the oops later on
> >>> only happens together with this warning at boot, or whether they're
> >>> not correlated?
> >>
> >> Looking through my logs, I can't find any instance of the oops without
> >> the warning at boot.  So I do think the later oops is entirely caused by
> >> the issue warned about in early boot.
> > 
> > Hm, I guess then we'd need to fix that boot-up warning. Can you try to
> > figure out why it's unhappy? On a hunch it could be that we call
> > drm_connector_register from the mst probe worker before the main
> > driver load thread has reached the drm_dev_register call. A few printk
> > to decide whether that's the case (plus a few boot-up tests to gather
> > the statistics, sorry about that) would be real great.
> 
> I think your suspicion is correct.
> 
> The WARNING is getting printed from CPU0 (the
> drm_dp_mst_link_probe_work() thread) and we can see the
> drm_connector_register()s happening in parallel on CPU1 while the
> WARNING is getting printed out.
> 
> This seems to happen very consistently when i915 is built into the kernel.

Do you have

commit e73ab00e9a0f1731f34d0620a9c55f5c30c4ad4e
Author: Daniel Vetter <daniel.vetter@xxxxxxxx>
Date:   Sun Dec 18 14:35:45 2016 +0100

    drm: prevent double-(un)registration for connectors

Lack of that would perfectly explain that oops ... Otherwise still no idea
what's going wrong.
-Daniel

> 
> > [    1.404237] drm_dev_register(00000000000002da)::209092608 cpu: 1
> > [    1.404284] drm_connector_register(ffff88040ed3e800)::379 connector->registered: 0 cpu: 0
> > [    1.404293] sysfs_create_dir_ns()::53 error: -2
> > [    1.404295] create_dir()::75 error: -2 cpu: 0
> > [    1.404298] ------------[ cut here ]------------
> > [    1.404304] WARNING: CPU: 0 PID: 3 at lib/kobject.c:249 kobject_add_internal+0x273/0x330
> > [    1.404308] kobject_add_internal failed for card0-DP-3 (error: -2 parent: card0)
> > [    1.404311] Modules linked in:
> > [    1.404316] CPU: 0 PID: 3 Comm: kworker/0:0 Not tainted 4.10.0-rc3-i915borked-dirty #66
> > [    1.404319] Hardware name: LENOVO 20F5S7V800/20F5S7V800, BIOS R02ET50W (1.23 ) 09/20/2016
> > [    1.404325] Workqueue: events_long drm_dp_mst_link_probe_work
> > [    1.404328] Call Trace:
> > [    1.404334]  dump_stack+0x67/0x99
> > [    1.404338]  __warn+0xd1/0xf0
> > [    1.404342]  warn_slowpath_fmt+0x4f/0x60
> > [    1.404345]  kobject_add_internal+0x273/0x330
> > [    1.404347]  kobject_add+0x65/0xb0
> > [    1.404352]  ? klist_init+0x31/0x40
> > [    1.404356]  device_add+0x102/0x5d0
> > [    1.404360]  ? kfree_const+0x22/0x30
> > [    1.404364]  device_create_groups_vargs+0xd8/0x100
> > [    1.404367]  device_create_with_groups+0x36/0x40
> > [    1.404370] drm_connector_register(ffff88040c779000)::379 connector->registered: 0 cpu: 1
> > [    1.404374]  ? vprintk_default+0x29/0x50
> > [    1.404375]  ? printk+0x4d/0x4f
> > [    1.404378]  drm_sysfs_connector_add+0x60/0xe0
> > [    1.404381]  drm_connector_register+0x4e/0x100
> > [    1.404383]  intel_dp_register_mst_connector+0x41/0x50
> > [    1.404385]  drm_dp_add_port+0x350/0x450
> > [    1.404388]  ? rcu_early_boot_tests+0x1/0x10
> > [    1.404390]  ? schedule_timeout+0x1cd/0x390
> > [    1.404392]  ? __might_sleep+0x4a/0x90
> > [    1.404394]  ? mutex_lock+0x25/0x50
> > [    1.404395]  ? drm_dp_mst_wait_tx_reply+0x118/0x1e0
> > [    1.404397]  ? prepare_to_wait_event+0x120/0x120
> > [    1.404399]  ? drm_dp_check_mstb_guid+0x3d/0x120
> > [    1.404401]  drm_dp_send_link_address+0x185/0x1f0
> > [    1.404403]  drm_dp_check_and_send_link_address+0xad/0xc0
> > [    1.404405]  drm_dp_mst_link_probe_work+0x57/0xa0
> > [    1.404407]  process_one_work+0x14b/0x430
> > [    1.404408]  worker_thread+0x12b/0x4a0
> > [    1.404410]  kthread+0x10c/0x140
> > [    1.404411]  ? process_one_work+0x430/0x430
> > [    1.404413]  ? kthread_create_on_node+0x40/0x40
> > [    1.404415]  ret_from_fork+0x27/0x40
> > [    1.404418] ---[ end trace 952a97b7cba4984f ]---
> > [    1.404420] drm_sysfs_connector_add() connector: ffff88040ed3e800 kdev: fffffffffffffffe
> > [    1.404422] [drm:drm_sysfs_connector_add] *ERROR* failed to register connector device: -2
> > [    1.404453] drm_sysfs_connector_add() connector: ffff88040c779000 kdev: ffff88040c771c00
> > [    1.404508] drm_connector_register(ffff88040c779000)::402 connector->registered: 1 cpu: 1
> > [    1.404512] drm_connector_register(ffff88040ed3b800)::379 connector->registered: 0 cpu: 1
> > [    1.404531] drm_sysfs_connector_add() connector: ffff88040ed3b800 kdev: ffff88040c772000
> > [    1.404559] drm_connector_register(ffff88040ed3b800)::402 connector->registered: 1 cpu: 1
> > [    1.404564] drm_connector_register(ffff88040ed3c000)::379 connector->registered: 0 cpu: 1
> > [    1.404583] drm_sysfs_connector_add() connector: ffff88040ed3c000 kdev: ffff88040c772400
> 

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch