On 2015-01-29T10:09:39+0200, Tomi Valkeinen wrote: > On 29/01/15 04:32, S. Gilles wrote: > > Since commit 92b004d1aa9f367c372511ca0330f58216b25703 : prevent use of > > logs after they have been freed, my i915 machine has no logo on boot > > (reverting that commit brings it back on recent trees). My .config > > builds nothing but wireless as =m, so I think this is a genuine false > > positive (as predicted by the commit). Examining an augmented dmesg, > > It's not so much about modules, but when the code tries to use the > logos. Drivers as modules might cause the use of logos to happen later, > but that's only one possible reason. > > > it appears that the framebuffer setup is too slow by about 0.3s, which > > I wouldn't really expect from this system/driver. > > > > Is this slowness considered worth fixing, or is this issue considered > > too cosmetic? (Or is this just PEBKAC?) > > > > Possibly useful information: > > > > $ lspci | grep VGA > > 00:02.0 VGA compatible controller: Intel Corporation 2nd Generation Core Processor Family Integrated Graphics Controller (rev 09) > > > > From various printk()s, it looks like the slow portion of > > fb_console_init() is restore_fbdev_mode(), specifically > > drm_mode_set_config_internal(), which takes about 0.45s, while the > > fb_logo_late_init() call happens about 0.15s into that. I can give the > > full details if requested. > > When does the driver probe() happen? Does the initialization happen > outside of the probe(), via workqueue or such? If so, then the fix is > valid for your case also, as the work could be ran after the logos have > been freed. It looks like the fix is indeed valid, since the initialization happens without probe() in the trace: the result of putting dump_stack() at the beginning of the relevant functions is (in far too much detail) ... [ 0.302391] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 3.19.0-rc5+ #26 [ 0.302476] Hardware name: LENOVO 4286CTO/4286CTO, BIOS 8DET42WW (1.12 ) 04/01/2011 [ 0.302561] ffff880138ffd000 ffff880139563c98 ffffffff817945db 0000000000000126 [ 0.302882] ffffffff81849d20 ffff880139563cc8 ffffffff813b7ec4 ffff880138ffd000 [ 0.303189] ffffffff81848b10 ffffffff81c3ad58 ffff880138ffd090 ffff880139563cf8 [ 0.303511] Call Trace: [ 0.303578] [<ffffffff817945db>] dump_stack+0x45/0x57 [ 0.303677] [<ffffffff813b7ec4>] i915_pci_probe+0x1a/0x68 [ 0.303769] [<ffffffff8131c209>] pci_device_probe+0x54/0xa3 [ 0.303850] [<ffffffff8144367d>] driver_probe_device+0x99/0x1c8 [ 0.303916] [<ffffffff81443841>] __driver_attach+0x5d/0x80 [ 0.303980] [<ffffffff814437e4>] ? __device_attach+0x38/0x38 [ 0.305851] [<ffffffff81441d7c>] bus_for_each_dev+0x7b/0x85 [ 0.305914] [<ffffffff81443240>] driver_attach+0x19/0x1b [ 0.305975] [<ffffffff81442f28>] bus_add_driver+0x109/0x1d3 [ 0.306038] [<ffffffff81443c20>] driver_register+0x8a/0xc7 [ 0.306141] [<ffffffff8131bf4b>] __pci_register_driver+0x5c/0x60 [ 0.306219] [<ffffffff81d052cc>] ? ftrace_define_fields_drm_vblank_event_delivered+0x9f/0x9f [ 0.306329] [<ffffffff813a5fa3>] drm_pci_init+0x4d/0xcd [ 0.306428] [<ffffffff81d052cc>] ? ftrace_define_fields_drm_vblank_event_delivered+0x9f/0x9f [ 0.306505] [<ffffffff81d05356>] i915_init+0x8a/0x92 [ 0.306566] [<ffffffff81d052cc>] ? ftrace_define_fields_drm_vblank_event_delivered+0x9f/0x9f [ 0.306650] [<ffffffff8100030d>] do_one_initcall+0xe9/0x172 [ 0.306746] [<ffffffff81ccefb1>] kernel_init_freeable+0x117/0x19f [ 0.306827] [<ffffffff81cce7c0>] ? initcall_blacklist+0xa3/0xa3 [ 0.306926] [<ffffffff8178e559>] ? rest_init+0xb6/0xb6 [ 0.306993] [<ffffffff8178e562>] kernel_init+0x9/0xd0 [ 0.307085] [<ffffffff8179ceec>] ret_from_fork+0x7c/0xb0 [ 0.307176] [<ffffffff8178e559>] ? rest_init+0xb6/0xb6 ... [ 0.646722] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 3.19.0-rc5+ #26 [ 0.646723] Hardware name: LENOVO 4286CTO/4286CTO, BIOS 8DET42WW (1.12 ) 04/01/2011 [ 0.646726] ffff8800b5aff000 ffff880139563e78 ffffffff817945db 0000000000000013 [ 0.646728] ffffffff81d00a08 ffff880139563e88 ffffffff81d00a1f ffff880139563ef8 [ 0.646730] ffffffff8100030d 0000000000000000 ffffffff81b7f6b8 0000019d00070007 [ 0.646730] Call Trace: [ 0.646733] [<ffffffff817945db>] dump_stack+0x45/0x57 [ 0.646736] [<ffffffff81d00a08>] ? fb_console_init+0x116/0x116 [ 0.646738] [<ffffffff81d00a1f>] fb_logo_late_init+0x17/0x22 [ 0.646741] [<ffffffff8100030d>] do_one_initcall+0xe9/0x172 [ 0.646744] [<ffffffff81ccefb1>] kernel_init_freeable+0x117/0x19f [ 0.646745] [<ffffffff81cce7c0>] ? initcall_blacklist+0xa3/0xa3 [ 0.646747] [<ffffffff8178e559>] ? rest_init+0xb6/0xb6 [ 0.646749] [<ffffffff8178e562>] kernel_init+0x9/0xd0 [ 0.646752] [<ffffffff8179ceec>] ret_from_fork+0x7c/0xb0 [ 0.646754] [<ffffffff8178e559>] ? rest_init+0xb6/0xb6 ... [ 1.162602] CPU: 1 PID: 6 Comm: kworker/u16:0 Not tainted 3.19.0-rc5+ #26 [ 1.162605] Hardware name: LENOVO 4286CTO/4286CTO, BIOS 8DET42WW (1.12 ) 04/01/2011 [ 1.162627] 0000000000000018 ffff8801395a3918 ffffffff817945db ffffffff81caeee0 [ 1.162634] 0000000000000018 ffff8801395a3938 ffffffff8178f5f7 0000000000000000 [ 1.162641] ffff8800b5ff0c00 ffff8801395a3968 ffffffff813321fb 0000000000000320 [ 1.162643] Call Trace: [ 1.162653] [<ffffffff817945db>] dump_stack+0x45/0x57 [ 1.162661] [<ffffffff8178f5f7>] fb_find_logo+0xd/0x43 [ 1.162669] [<ffffffff813321fb>] fb_prepare_logo+0x87/0x12d [ 1.162675] [<ffffffff81328fed>] fbcon_prepare_logo+0x7f/0x2e8 [ 1.162680] [<ffffffff8132b3b9>] fbcon_init+0x3d9/0x447 [ 1.162688] [<ffffffff813817de>] visual_init+0xb7/0x10d [ 1.162695] [<ffffffff81383000>] do_bind_con_driver+0x1ab/0x2cd [ 1.162702] [<ffffffff813835e1>] do_take_over_console+0x132/0x162 [ 1.162707] [<ffffffff813292ac>] do_fbcon_takeover+0x56/0x9a [ 1.162712] [<ffffffff8132cb6a>] fbcon_event_notify+0x31c/0x644 [ 1.162718] [<ffffffff810bcf4f>] notifier_call_chain+0x39/0x5c [ 1.162723] [<ffffffff810bd208>] __blocking_notifier_call_chain+0x47/0x60 [ 1.162729] [<ffffffff810bd230>] blocking_notifier_call_chain+0xf/0x11 [ 1.162735] [<ffffffff81331cc3>] fb_notifier_call_chain+0x16/0x18 [ 1.162741] [<ffffffff81333b50>] register_framebuffer+0x261/0x299 [ 1.162750] [<ffffffff8139bcfb>] drm_fb_helper_initial_config+0x26e/0x328 [ 1.162757] [<ffffffff8141da68>] intel_fbdev_initial_config+0x16/0x18 [ 1.162762] [<ffffffff810be0a0>] async_run_entry_fn+0x33/0xca [ 1.162770] [<ffffffff810b800b>] process_one_work+0x223/0x3f9 [ 1.162775] [<ffffffff810b7f8f>] ? process_one_work+0x1a7/0x3f9 [ 1.162781] [<ffffffff810b8905>] worker_thread+0x260/0x354 [ 1.162788] [<ffffffff810b86a5>] ? cancel_delayed_work_sync+0x10/0x10 [ 1.162794] [<ffffffff810bc333>] kthread+0xe8/0xf0 [ 1.162802] [<ffffffff810bc24b>] ? kthread_create_on_node+0x1b1/0x1b1 [ 1.162810] [<ffffffff8179ceec>] ret_from_fork+0x7c/0xb0 [ 1.162817] [<ffffffff810bc24b>] ? kthread_create_on_node+0x1b1/0x1b1 ... > However, it does seem that the fix seems to cause logos to disappear for > many people. I'd be interesting to know how many of those cases were > working by luck, either by > > 1) an async work being ran fast enough, before the logos had been freed > 2) the use of logos happening after the logos had been freed, but if no > one had trashed the logo memory yet, it still works In my case, it looks like #1 is the case: free_initmem() was called ~6.96s into boot on the run matching the traces above, so the initdata looks safe barring async trickery. > I don't care so much about the logo myself but people do seem to like > it, so perhaps we need to change the code as Thierry suggested: > allocating memory for the logos and keeping them in memory until someone > uses them the first time, and then free the memory. I'm not too concerned about the pixels myself, but I was concerned that the initialization was happening slow enough to be caught by this (perhaps this might have been a warning sign if setting up the console was depending unsafely on other initdata?). It is also rather obvious, so it's something a novice like myself can easily bisect and report. -- S. Gilles -- To unsubscribe from this list: send the line "unsubscribe linux-fbdev" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
