radeon_atrm_get_bios() seems to be quite slow

Petr Štetiar ynezz at true.cz
Mon Jan 2 14:45:08 PST 2012


Hi,

for some time (I don't remember since when) I'm experiencing quite strange
long boot times on my laptop. I've tracked it down to the GPU init code,
namely to function radeon_atrm_get_bios(). This function takes about 25-30
seconds to complete on my laptop on every reboot.

I believe that it's not normal, nor expected behaviour, so I've added some
debug printks in the code as can be seen in attached patch and the damn slow
boot can be seen in attached dmesg log also.

I would like to note, that if I rmmod/modprobe radeon module after that long
boot, it takes about 2 seconds to complete. To me it seems, like some issue in
acpi_evaluate_object() but I'm not sure 100% yet. Does anyone have any clue
what could be happening there?

I'm running vanilla 3.1.6 if it matters.

Thanks a lot for any pointers.

-- ynezz
-------------- next part --------------
[    3.285892] [drm] radeon defaulting to kernel modesetting.
[    3.285956] [drm] radeon kernel modesetting enabled.
[    3.286028] VGA switcheroo: detected switching method \_SB_.PCI0.VGA_.ATPX handle
[    3.286147] radeon 0000:01:00.0: enabling device (0000 -> 0003)
[    3.286213] radeon 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    3.286278] radeon 0000:01:00.0: setting latency timer to 64
[    3.286520] [drm] initializing kernel modesetting (CEDAR 0x1002:0x68E0 0x1043:0x1C12).
[    3.286659] [drm] register mmio base: 0xF0020000
[    3.286716] [drm] register mmio size: 131072
[    3.286771] hhere1
[    3.286820] hhere2
[    3.286868] here1
[    3.286917] here1.1
[    3.286966] here1.2
[    3.287016] bios_chunk: 000 offset: 0x0 len: 0x1000
[    3.350889] usb 2-1: new high speed USB device number 2 using ehci_hcd
[    3.455607] e1000e 0000:00:19.0: eth0: (PCI Express:2.5GT/s:Width x1) 20:cf:30:7d:d6:ab
[    3.455707] e1000e 0000:00:19.0: eth0: Intel(R) PRO/1000 Network Connection
[    3.455827] e1000e 0000:00:19.0: eth0: MAC: 9, PHY: 10, PBA No: FFFFFF-0FF
[    3.455967] agpgart-intel 0000:00:00.0: Intel HD Graphics Chipset
[    3.456212] agpgart-intel 0000:00:00.0: detected gtt size: 2097152K total, 262144K mappable
[    3.457306] agpgart-intel 0000:00:00.0: detected 32768K stolen memory
[    3.457585] agpgart-intel 0000:00:00.0: AGP aperture is 256M @ 0xd0000000
[    3.501644] hub 2-1:1.0: USB hub found
[    3.501860] hub 2-1:1.0: 8 ports detected
[    3.550827] i915 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    3.550893] i915 0000:00:02.0: setting latency timer to 64
[    3.581013] usb 1-1.5: new full speed USB device number 3 using ehci_hcd
[    3.651059] bios_chunk: 001 offset: 0x1000 len: 0x1000
[    3.780863] usb 2-1.6: new high speed USB device number 3 using ehci_hcd
[    4.650453] bios_chunk: 002 offset: 0x2000 len: 0x1000
[    6.139584] bios_chunk: 003 offset: 0x3000 len: 0x1000
[    7.568795] bios_chunk: 004 offset: 0x4000 len: 0x1000
[    9.027979] bios_chunk: 005 offset: 0x5000 len: 0x1000
[   10.457184] bios_chunk: 006 offset: 0x6000 len: 0x1000
[   11.886329] bios_chunk: 007 offset: 0x7000 len: 0x1000
[   13.325589] bios_chunk: 008 offset: 0x8000 len: 0x1000
[   15.014631] bios_chunk: 009 offset: 0x9000 len: 0x1000
[   16.603742] bios_chunk: 010 offset: 0xa000 len: 0x1000
[   18.212843] bios_chunk: 011 offset: 0xb000 len: 0x1000
[   19.801900] bios_chunk: 012 offset: 0xc000 len: 0x1000
[   21.501003] bios_chunk: 013 offset: 0xd000 len: 0x1000
[   23.160075] bios_chunk: 014 offset: 0xe000 len: 0x1000
[   24.839148] bios_chunk: 015 offset: 0xf000 len: 0x1000
[   24.998874] bios_chunk: 016 offset: 0x10000 len: 0x1000
[   24.999002] bios_chunk: 017 offset: 0x11000 len: 0x1000
[   24.999108] bios_chunk: 018 offset: 0x12000 len: 0x1000
[   24.999216] bios_chunk: 019 offset: 0x13000 len: 0x1000
[   24.999325] bios_chunk: 020 offset: 0x14000 len: 0x1000
[   24.999435] bios_chunk: 021 offset: 0x15000 len: 0x1000
[   24.999544] bios_chunk: 022 offset: 0x16000 len: 0x1000
[   24.999654] bios_chunk: 023 offset: 0x17000 len: 0x1000
[   24.999762] bios_chunk: 024 offset: 0x18000 len: 0x1000
[   24.999868] bios_chunk: 025 offset: 0x19000 len: 0x1000
[   24.999974] bios_chunk: 026 offset: 0x1a000 len: 0x1000
[   25.000083] bios_chunk: 027 offset: 0x1b000 len: 0x1000
[   25.000192] bios_chunk: 028 offset: 0x1c000 len: 0x1000
[   25.000301] bios_chunk: 029 offset: 0x1d000 len: 0x1000
[   25.000410] bios_chunk: 030 offset: 0x1e000 len: 0x1000
[   25.000520] bios_chunk: 031 offset: 0x1f000 len: 0x1000
[   25.000627] bios_chunk: 032 offset: 0x20000 len: 0x1000
[   25.000732] bios_chunk: 033 offset: 0x21000 len: 0x1000
[   25.000841] bios_chunk: 034 offset: 0x22000 len: 0x1000
[   25.000950] bios_chunk: 035 offset: 0x23000 len: 0x1000
[   25.001058] bios_chunk: 036 offset: 0x24000 len: 0x1000
[   25.001167] bios_chunk: 037 offset: 0x25000 len: 0x1000
[   25.001276] bios_chunk: 038 offset: 0x26000 len: 0x1000
[   25.001384] bios_chunk: 039 offset: 0x27000 len: 0x1000
[   25.001489] bios_chunk: 040 offset: 0x28000 len: 0x1000
[   25.001596] bios_chunk: 041 offset: 0x29000 len: 0x1000
[   25.001705] bios_chunk: 042 offset: 0x2a000 len: 0x1000
[   25.001814] bios_chunk: 043 offset: 0x2b000 len: 0x1000
[   25.001924] bios_chunk: 044 offset: 0x2c000 len: 0x1000
[   25.002033] bios_chunk: 045 offset: 0x2d000 len: 0x1000
[   25.002143] bios_chunk: 046 offset: 0x2e000 len: 0x1000
[   25.002250] bios_chunk: 047 offset: 0x2f000 len: 0x1000
[   25.002355] bios_chunk: 048 offset: 0x30000 len: 0x1000
[   25.002463] bios_chunk: 049 offset: 0x31000 len: 0x1000
[   25.002573] bios_chunk: 050 offset: 0x32000 len: 0x1000
[   25.002682] bios_chunk: 051 offset: 0x33000 len: 0x1000
[   25.002791] bios_chunk: 052 offset: 0x34000 len: 0x1000
[   25.002900] bios_chunk: 053 offset: 0x35000 len: 0x1000
[   25.003007] bios_chunk: 054 offset: 0x36000 len: 0x1000
[   25.003112] bios_chunk: 055 offset: 0x37000 len: 0x1000
[   25.003219] bios_chunk: 056 offset: 0x38000 len: 0x1000
[   25.003329] bios_chunk: 057 offset: 0x39000 len: 0x1000
[   25.003437] bios_chunk: 058 offset: 0x3a000 len: 0x1000
[   25.003546] bios_chunk: 059 offset: 0x3b000 len: 0x1000
[   25.003655] bios_chunk: 060 offset: 0x3c000 len: 0x1000
[   25.003763] bios_chunk: 061 offset: 0x3d000 len: 0x1000
[   25.003870] bios_chunk: 062 offset: 0x3e000 len: 0x1000
[   25.003976] bios_chunk: 063 offset: 0x3f000 len: 0x1000
[   25.004085] here1.3
[   25.004141] here1.4
[   25.004192] here2.1
[   25.004247] here2.2
[   25.004301] here2.3
[   25.004355] here2.4
[   25.004412] hhere3
[   25.004467] hhere4
[   25.004522] here3
[   25.004574] here4
[   25.004629] Pid: 137, comm: modprobe Not tainted 3.1.6+ #13
[   25.004691] Call Trace:
[   25.004777]  [<ffffffffa008b28c>] radeon_atombios_init+0xec/0x180 [radeon]
[   25.004864]  [<ffffffffa0113263>] evergreen_init+0xb3/0x300 [radeon]
[   25.004944]  [<ffffffffa008ae39>] radeon_device_init+0x3e9/0x4a0 [radeon]
[   25.005028]  [<ffffffffa008cf61>] radeon_driver_load_kms+0xb1/0x160 [radeon]
[   25.005101]  [<ffffffff81397260>] drm_get_pci_dev+0x190/0x2b0
[   25.005184]  [<ffffffffa0122a18>] radeon_pci_probe+0xaa/0x304 [radeon]
[   25.005256]  [<ffffffff812ec08f>] local_pci_probe+0x5f/0xd0
[   25.005319]  [<ffffffff812ed3b1>] pci_device_probe+0x101/0x120
[   25.005391]  [<ffffffff813acdaa>] ? driver_sysfs_add+0x7a/0xb0
[   25.005458]  [<ffffffff813acf06>] driver_probe_device+0x96/0x1c0
[   25.005527]  [<ffffffff813ad0cb>] __driver_attach+0x9b/0xa0
[   25.005593]  [<ffffffff813ad030>] ? driver_probe_device+0x1c0/0x1c0
[   25.005662]  [<ffffffff813ac338>] bus_for_each_dev+0x68/0x90
[   25.005729]  [<ffffffff813acd2e>] driver_attach+0x1e/0x20
[   25.005795]  [<ffffffff813ac61d>] bus_add_driver+0xcd/0x270
[   25.005863]  [<ffffffff813ad768>] driver_register+0x78/0x140
[   25.005928]  [<ffffffff812ed636>] __pci_register_driver+0x56/0xd0
[   25.005996]  [<ffffffff81397494>] drm_pci_init+0x114/0x130
[   25.006060]  [<ffffffff813a740a>] ? vga_switcheroo_register_handler+0x3a/0x60
[   25.006134]  [<ffffffffa0167000>] ? 0xffffffffa0166fff
[   25.006206]  [<ffffffffa01670ec>] radeon_init+0xec/0xee [radeon]
[   25.006277]  [<ffffffff810001d3>] do_one_initcall+0x43/0x170
[   25.006344]  [<ffffffff8108c230>] sys_init_module+0x90/0x1e0
[   25.006412]  [<ffffffff815a462b>] system_call_fastpath+0x16/0x1b
[   25.006481] ATOM BIOS: ASID:0A320240.002
[   25.006540] here5
[   25.006600] hhere5
[   25.006656] hhere6
[   25.006758] hhere8
[   25.006825] radeon 0000:01:00.0: VRAM: 512M 0x0000000000000000 - 0x000000001FFFFFFF (512M used)
[   25.006925] radeon 0000:01:00.0: GTT: 512M 0x0000000020000000 - 0x000000003FFFFFFF
[   25.007027] mtrr: no more MTRRs available
[   25.007089] [drm] Detected VRAM RAM=512M, BAR=256M
[   25.007153] [drm] RAM width 64bits DDR
[   25.007396] [TTM] Zone  kernel: Available graphics memory: 1922676 kiB.
[   25.007472] [TTM] Initializing pool allocator.
[   25.007562] [drm] radeon: 512M of VRAM memory ready
[   25.007626] [drm] radeon: 512M of GTT memory ready.
[   25.007694] [drm] Supports vblank timestamp caching Rev 1 (10.10.2010).
[   25.007763] [drm] Driver supports precise vblank timestamp query.
[   25.007864] radeon 0000:01:00.0: irq 46 for MSI/MSI-X
[   25.007869] radeon 0000:01:00.0: radeon: using MSI.
[   25.007959] [drm] radeon: irq initialized.
[   25.008023] [drm] GART: num cpu pages 131072, num gpu pages 131072
[   25.008605] [drm] Loading CEDAR Microcode
[   25.014621] radeon 0000:01:00.0: WB enabled
[   25.031264] [drm] ring test succeeded in 1 usecs
[   25.031424] [drm] radeon: ib pool ready.
[   25.031583] [drm] ib test succeeded in 0 usecs
[   25.032061] [drm] Radeon Display Connectors
[   25.032120] [drm] Connector 0:
[   25.032173] [drm]   LVDS
[   25.032224] [drm]   DDC: 0x6560 0x6560 0x6564 0x6564 0x6568 0x6568 0x656c 0x656c
[   25.032307] [drm]   Encoders:
[   25.032361] [drm]     LCD1: INTERNAL_UNIPHY
[   25.032418] [drm] Connector 1:
[   25.032475] [drm]   DisplayPort
[   25.032532] [drm]   HPD2
[   25.032589] [drm]   DDC: 0x6430 0x6430 0x6434 0x6434 0x6438 0x6438 0x643c 0x643c
[   25.033259] [drm]   Encoders:
[   25.033316] [drm]     DFP1: INTERNAL_UNIPHY1
[   25.033378] [drm] Connector 2:
[   25.033433] [drm]   HDMI-A
[   25.033490] [drm]   HPD1
[   25.033543] [drm]   DDC: 0x6440 0x6440 0x6444 0x6444 0x6448 0x6448 0x644c 0x644c
[   25.033640] [drm]   Encoders:
[   25.033697] [drm]     DFP2: INTERNAL_UNIPHY1
[   25.033758] [drm] Connector 3:
[   25.033815] [drm]   DVI-D
[   25.033873] [drm]   HPD3
[   25.033926] [drm]   DDC: 0x6450 0x6450 0x6454 0x6454 0x6458 0x6458 0x645c 0x645c
[   25.034022] [drm]   Encoders:
[   25.034080] [drm]     DFP3: INTERNAL_UNIPHY2
[   25.034141] [drm] Connector 4:
[   25.034199] [drm]   VGA
[   25.034255] [drm]   DDC: 0x64d8 0x64d8 0x64dc 0x64dc 0x64e0 0x64e0 0x64e4 0x64e4
[   25.034349] [drm]   Encoders:
[   25.034406] [drm]     CRT1: INTERNAL_KLDSCP_DAC1
[   25.044335] [drm] Radeon display connector LVDS-1: No monitor connected or invalid EDID
[   26.078175] [drm] Radeon display connector DP-1: No monitor connected or invalid EDID
[   26.088286] [drm] Radeon display connector HDMI-A-1: No monitor connected or invalid EDID
[   26.098403] [drm] Radeon display connector DVI-D-1: No monitor connected or invalid EDID
[   26.108527] [drm] Radeon display connector VGA-1: No monitor connected or invalid EDID
[   26.108674] [drm] Internal thermal controller with fan control
[   26.108816] [drm] radeon: power management initialized
[   26.170796] [drm] fb mappable at 0xE0141000
[   26.170859] [drm] vram apper at 0xE0000000
[   26.170917] [drm] size 4325376
[   26.170974] [drm] fb depth is 24
[   26.171029] [drm]    pitch is 5632
[   26.750142] Console: switching to colour frame buffer device 170x48
[   26.752500] fb0: radeondrmfb frame buffer device
[   26.752501] drm: registered panic notifier
[   26.752548] [drm] Initialized radeon 2.11.0 20080528 for 0000:01:00.0 on minor 0
[   26.808342] i915 0000:00:02.0: irq 47 for MSI/MSI-X
[   26.808347] [drm] Supports vblank timestamp caching Rev 1 (10.10.2010).
[   26.808381] [drm] Driver supports precise vblank timestamp query.
[   26.808518] vga_switcheroo: enabled
[   26.808560] radeon atpx: version is 1
[   26.808603] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=io+mem,decodes=none:owns=none
[   26.808638] vgaarb: device changed decodes: PCI:0000:00:02.0,olddecodes=io+mem,decodes=none:owns=io+mem
[   26.870372] fixme: max PWM is zero.
[   27.499066] fbcon: inteldrmfb (fb1) is primary device
[   27.499102] fbcon: Remapping primary device, fb1, to tty 1-63
[   27.854339] fb1: inteldrmfb frame buffer device
[   27.856715] acpi device:44: registered as cooling_device4
[   27.857000] input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/device:3f/LNXVIDEO:00/input/input4
[   27.857103] ACPI: Video Device [VGA] (multi-head: yes  rom: no  post: no)
[   27.859129] acpi device:48: registered as cooling_device5
[   27.859367] input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/LNXVIDEO:01/input/input5
[   27.859497] ACPI: Video Device [VGA1] (multi-head: yes  rom: no  post: no)
[   27.859555] [drm] Initialized i915 1.6.0 20080730 for 0000:00:02.0 on minor 1
-------------- next part --------------
A non-text attachment was scrubbed...
Name: drm-debug.patch
Type: text/x-diff
Size: 3960 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/dri-devel/attachments/20120102/98274242/attachment-0001.patch>


More information about the dri-devel mailing list