Re: BUG: fb_imageblit called before fb_check_var and fb_set_par function

["Antonino A. Daplas" <adaplas@gmail.com>]

Knut Petersen wrote:
> Hi Antonio,
> 
>> Perhaps, if you have the time, you can instrument it better so we can 
>> pinpoint
>> where this unwanted calls are coming from.  Months were spent trying 
>> to fix this
>> problem, mainly by BenH, and I don't want any stones left unturned. 
> 
> So lets conclude: The problem is _not_ fixed and still present in 
> 2.6.13-rc7.
> I added BenH and Andrew Morton to the cc-list.
> 
> I added a printk at the start of redraw_screen() and a show_trace() in 
> cyblafb_sync().
> 
> Imho
>   - there is a bug of the trident driver in X that should _never_ 
> disable mmio for
>     the cyberblade core if it is started with mmio enabled.  A bug Alan 
> Hourihane
>     should fix.
>  - there also is a serious kernel bug as no drawing function must be called
>     prior to setting up the framebuffer driver by executing the 
> set_par() call.
> 
> I´m happy to have learned enough about the low -level framebuffer layer,
> but I´m definitely not qualified to do fixed in char/vt.c, 
> char/vt_ioctl.c etc.
> 
> Read some shortened dmesg logs:
> (cyblafb: Switching ... marks the start of the fb_set_par function)
> 
> ==========
> First log:
> ==========
> 1-init to runlevel 3
> 2-login as root on tty1
> 3-init 5
> 4-switching back to tty1 with ctrl-alt-f1
> 
> ...
> Detected 533.506 MHz processor.
> Using tsc for high-res timesource
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> Console: colour dummy device 80x25
> ...
> ACPI: Assume root bridge [\_SB_.PCI0] bus is 0
> Boot video device is 0000:01:00.0
> ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
> ...
> cyblafb: CyblaFB version 0.53 initializing
> ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 11
> PCI: setting IRQ 11 as level-triggered
> ACPI: PCI Interrupt 0000:01:00.0[A] -> Link [LNKA] -> GSI 11 (level, 
> low) -> IRQ 11
> cyblafb: framebuffer size = 8192 Kb
> cyblafb: detected startup mode: fbset -g 1280 1024 1280 ??? 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> cyblafb: Switching to new mode: fbset -g 1280 1024 1280 2662 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> Console: switching to colour frame buffer device 160x64
> ...
> ACPI: PCI Interrupt 0000:00:11.5[C] -> Link [LNKC] -> GSI 12 (level, 
> low) -> IRQ 12
> PCI: Setting latency timer of device 0000:00:11.5 to 64
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> eth0: no IPv6 routers present
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> ******** Now logged in as root on tty1
> redraw_screen: called with is_switch 1 and vc->vc_mode 0
> ******** X has been started here, we are in xterm. Now ctrl-alt-f1:
> redraw_screen: called with is_switch 1 and vc->vc_mode 0
> cyblafb: Switching to new mode: fbset -g 1280 1024 1280 2662 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> ******** We switched back to tty1
> 
> As you can see, redraw_screen is called prior to cyblafb_setpar, but 
> nothing bad is
> triggered because the X trident buffer does not disable mmio.
> ===========
> Second log:
> ===========
> 1-init to runlevel 5
> 2-switching to tty1 with ctrl-alt-f1
> 
> ...
> Detected 533.508 MHz processor.
> Using tsc for high-res timesource
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> Console: colour dummy device 80x25
> ...
> ACPI: Assume root bridge [\_SB_.PCI0] bus is 0
> Boot video device is 0000:01:00.0
> ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
> ...
> cyblafb: CyblaFB version 0.53 initializing
> ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 11
> PCI: setting IRQ 11 as level-triggered
> ACPI: PCI Interrupt 0000:01:00.0[A] -> Link [LNKA] -> GSI 11 (level, 
> low) -> IRQ 11
> cyblafb: framebuffer size = 8192 Kb
> cyblafb: detected startup mode: fbset -g 1280 1024 1280 ??? 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> cyblafb: Switching to new mode: fbset -g 1280 1024 1280 2662 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> Console: switching to colour frame buffer device 160x64
> ...
> ACPI: PCI Interrupt 0000:00:11.5[C] -> Link [LNKC] -> GSI 12 (level, 
> low) -> IRQ 12
> PCI: Setting latency timer of device 0000:00:11.5 to 64
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> eth0: no IPv6 routers present
> redraw_screen: called with is_switch 1 and vc->vc_mode 0
> ******** X has been started here, we are in xterm

So X is already started here, but vc->vc_mode is still KD_TEXT.

> ******** ctrl-alt-f1
> redraw_screen: called with is_switch 1 and vc->vc_mode 0

Back to console mode, vc->vc_mode is correctly KD_TEXT.  But
the kernel never detected a mode change. How could it, if the
previous mode was also KD_TEXT?
 
> cyblafb: GRAPHICS ENGINE TIMED OUT!
> [<c0246abd>] cyblafb_imageblit+0xad/0x230
> [<c0241a3b>] bit_putcs+0x2eb/0x560
> [<c01138a5>] __wake_up_common+0x35/0x70
> [<c023dba8>] fbcon_putcs+0x168/0x210
> [<c028c11b>] do_update_region+0x11b/0x180
> [<c028cc13>] redraw_screen+0x143/0x1e0
> [<c0288788>] complete_change_console+0x28/0xd0
> [<c0287cbd>] vt_ioctl+0x111d/0x1aa0
> [<c014886e>] __handle_mm_fault+0x13e/0x180
> [<c011174d>] do_page_fault+0x19d/0x550
> [<c03a7dd7>] schedule+0x337/0x670
> [<c0286ba0>] vt_ioctl+0x0/0x1aa0
> [<c0281fbc>] tty_ioctl+0x17c/0x410
> [<c011364a>] scheduler_tick+0x17a/0x310
> [<c0169d98>] do_ioctl+0x48/0x80
> [<c0169f2a>] vfs_ioctl+0x5a/0x1d0
> [<c016a0e6>] sys_ioctl+0x46/0x60
> [<c0102909>] syscall_call+0x7/0xb

And there you go, without a mode change (KD_GRAPHICS->KD_TEXT),
the console thinks a set_var/set_par is unnecessary.  This triggers
the bug (ouch).

> cyblafb: Switching to new mode: fbset -g 1280 1024 1280 2662 8 -t 7407 
> 232 16 39 0 160 3
> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> ******** Now logged in as root on tty1
> redraw_screen: called with is_switch 1 and vc->vc_mode 1
> ******** switched to xterm

At this point, everything works. In this case, X is active, so
vc->vc_mode is correctly set to KD_GRAPHICS.. .

> redraw_screen: called with is_switch 1 and vc->vc_mode 0

... and when it switches to KD_TEXT, the kernel detects the change,...

> cyblafb: Switching to new mode: fbset -g 1280 1024 1280 2662 8 -t 7407 
> 232 16 39 0 160 3

...calls set_var()/set_par...

> redraw_screen: called with is_switch 0 and vc->vc_mode 0
> ******** switched back to tty1
> 

...and the driver happily draws to the screen. No bug. 

I believe, from here on, everything will work as expected.

So it seems that when kdm loads the first time, it failed to set the
mode to KD_GRAPHICS which triggered the bug. Maybe it's a bug in
kdm then?

Tony 


-------------------------------------------------------
SF.Net email is Sponsored by the Better Software Conference & EXPO
September 19-22, 2005 * San Francisco, CA * Development Lifecycle Practices
Agile & Plan-Driven Development * Managing Projects & Teams * Testing & QA
Security * Process Improvement & Measurement * http://www.sqe.com/bsce5sf