Bug 106938

Summary: Module *radeon* takes over two seconds to load
Product: DRI Reporter: Paul Menzel <paulepanter>
Component: DRM/RadeonAssignee: Default DRI bug account <dri-devel>
Status: RESOLVED NOTABUG QA Contact:
Severity: normal    
Priority: medium CC: paulepanter, pmenzel+bugs.freedesktop.org
Version: DRI git   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: i915 features:
Attachments:
Description Flags
Linux 4.16.12 messages none

Description Paul Menzel 2018-06-17 08:13:07 UTC 
Created attachment 140184 [details]
Linux 4.16.12 messages

On a Asus F2A85-M PRO with Linux 4.16.12 from Debian Sid/unstable, according to *initcall_debug*, the module *radeon* takes over two seconds to load.

I blacklisted the module *radeon*, started the system, and loaded it *manually*.

```
$ more /proc/version
Linux version 4.16.0-0.bpo.2-amd64 (debian-kernel@lists.debian.org) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1)) #1 SMP Debian 4.16
.12-1~bpo9+1 (2018-06-03)
$ sudo dmidecode -t bios
# dmidecode 3.0
Getting SMBIOS data from sysfs.
SMBIOS 2.7 present.

Handle 0x0000, DMI type 0, 24 bytes
BIOS Information
	Vendor: American Megatrends Inc.
	Version: 6601
	Release Date: 11/25/2014
	Address: 0xF0000
	Runtime Size: 64 kB
	ROM Size: 8192 kB
	Characteristics:
		PCI is supported
		BIOS is upgradeable
		BIOS shadowing is allowed
		Boot from CD is supported
		Selectable boot is supported
		BIOS ROM is socketed
		EDD is supported
		5.25"/1.2 MB floppy services are supported (int 13h)
		3.5"/720 kB floppy services are supported (int 13h)
		3.5"/2.88 MB floppy services are supported (int 13h)
		Print screen service is supported (int 5h)
		8042 keyboard services are supported (int 9h)
		Serial services are supported (int 14h)
		Printer services are supported (int 17h)
		ACPI is supported
		USB legacy is supported
		BIOS boot specification is supported
		Targeted content distribution is supported
		UEFI is supported
	BIOS Revision: 4.6

Handle 0x0049, DMI type 13, 22 bytes
BIOS Language Information
	Language Description Format: Long
	Installable Languages: 8
		en|US|iso8859-1
		fr|FR|iso8859-1
		es|ES|iso8859-1
		de|DE|iso8859-1
		ru|RU|iso8859-5
		ja|JP|unicode
		zh|TW|unicode
		zh|CN|unicode
	Currently Installed Language: en|US|iso8859-1
$ sudo modprobe radeon
$ sudo dmesg
[…]
[  102.886209] calling  radeon_init+0x0/0xb0 [radeon] @ 12952
[  102.886211] [drm] radeon kernel modesetting enabled.
[  102.887680] [drm] initializing kernel modesetting (ARUBA 0x1002:0x9996 0x1043:0x8526 0x00).
[  102.887766] ATOM BIOS: 113
[  102.887853] radeon 0000:00:01.0: VRAM: 768M 0x0000000000000000 - 0x000000002FFFFFFF (768M used)
[  102.887856] radeon 0000:00:01.0: GTT: 1024M 0x0000000030000000 - 0x000000006FFFFFFF
[  102.887859] [drm] Detected VRAM RAM=768M, BAR=256M
[  102.887860] [drm] RAM width 64bits DDR
[  102.888845] [TTM] Zone  kernel: Available graphics memory: 1640126 kiB
[  102.888847] [TTM] Initializing pool allocator
[  102.888850] [TTM] Initializing DMA pool allocator
[  102.888872] [drm] radeon: 768M of VRAM memory ready
[  102.888873] [drm] radeon: 1024M of GTT memory ready.
[  102.888881] [drm] Loading ARUBA Microcode
[  102.889382] radeon 0000:00:01.0: firmware: direct-loading firmware radeon/ARUBA_pfp.bin
[  102.889682] radeon 0000:00:01.0: firmware: direct-loading firmware radeon/ARUBA_me.bin
[  102.889855] radeon 0000:00:01.0: firmware: direct-loading firmware radeon/ARUBA_rlc.bin
[  102.889860] [drm] Internal thermal controller without fan control
[  102.890007] [drm] radeon: dpm initialized
[  102.891095] radeon 0000:00:01.0: firmware: direct-loading firmware radeon/TAHITI_uvd.bin
[  102.891524] radeon 0000:00:01.0: firmware: direct-loading firmware radeon/TAHITI_vce.bin
[  102.892233] [drm] Found VCE firmware/feedback version 50.0.1 / 17!
[  102.892252] [drm] GART: num cpu pages 262144, num gpu pages 262144
[  102.901483] [drm] PCIE GART of 1024M enabled (table at 0x00000000001D6000).
[  102.901634] radeon 0000:00:01.0: WB enabled
[  102.901637] radeon 0000:00:01.0: fence driver on ring 0 use gpu addr 0x0000000030000c00 and cpu addr 0x000000004ecba740
[  102.902013] radeon 0000:00:01.0: fence driver on ring 5 use gpu addr 0x0000000000075a18 and cpu addr 0x000000001e5cb786
[  102.922033] radeon 0000:00:01.0: fence driver on ring 6 use gpu addr 0x0000000030000c18 and cpu addr 0x0000000041004126
[  102.922035] radeon 0000:00:01.0: fence driver on ring 7 use gpu addr 0x0000000030000c1c and cpu addr 0x00000000790037d4
[  102.922036] radeon 0000:00:01.0: fence driver on ring 1 use gpu addr 0x0000000030000c04 and cpu addr 0x000000001498f18b
[  102.922037] radeon 0000:00:01.0: fence driver on ring 2 use gpu addr 0x0000000030000c08 and cpu addr 0x0000000078dabdd0
[  102.922038] radeon 0000:00:01.0: fence driver on ring 3 use gpu addr 0x0000000030000c0c and cpu addr 0x000000002fbb9e93
[  102.922039] radeon 0000:00:01.0: fence driver on ring 4 use gpu addr 0x0000000030000c10 and cpu addr 0x000000008761b2bb
[  102.922050] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[  102.922051] [drm] Driver supports precise vblank timestamp query.
[  102.922052] radeon 0000:00:01.0: radeon: MSI limited to 32-bit
[  102.922097] radeon 0000:00:01.0: radeon: using MSI.
[  102.922118] [drm] radeon: irq initialized.
[  102.940486] [drm] ring test on 0 succeeded in 2 usecs
[  102.940496] [drm] ring test on 3 succeeded in 3 usecs
[  102.940503] [drm] ring test on 4 succeeded in 3 usecs
[  102.986224] [drm] ring test on 5 succeeded in 2 usecs
[  103.006092] [drm] UVD initialized successfully.
[  103.115293] [drm] ring test on 6 succeeded in 18 usecs
[  103.115302] [drm] ring test on 7 succeeded in 3 usecs
[  103.115302] [drm] VCE initialized successfully.
[  103.115467] [drm] ib test on ring 0 succeeded in 0 usecs
[  103.115522] [drm] ib test on ring 3 succeeded in 0 usecs
[  103.115575] [drm] ib test on ring 4 succeeded in 0 usecs
[  103.648614] [drm] ib test on ring 5 succeeded
[  104.192640] [drm] ib test on ring 6 succeeded
[  104.704646] [drm] ib test on ring 7 succeeded
[  104.705559] [drm] Radeon Display Connectors
[  104.705561] [drm] Connector 0:
[  104.705562] [drm]   DP-1
[  104.705564] [drm]   HPD1
[  104.705567] [drm]   DDC: 0x6530 0x6530 0x6534 0x6534 0x6538 0x6538 0x653c 0x653c
[  104.705567] [drm]   Encoders:
[  104.705569] [drm]     DFP1: INTERNAL_UNIPHY2
[  104.705570] [drm] Connector 1:
[  104.705571] [drm]   VGA-1
[  104.705572] [drm]   HPD2
[  104.705574] [drm]   DDC: 0x6540 0x6540 0x6544 0x6544 0x6548 0x6548 0x654c 0x654c
[  104.705575] [drm]   Encoders:
[  104.705576] [drm]     CRT1: INTERNAL_UNIPHY2
[  104.705576] [drm]     CRT1: NUTMEG
[  104.705577] [drm] Connector 2:
[  104.705578] [drm]   DVI-D-1
[  104.705579] [drm]   HPD3
[  104.705581] [drm]   DDC: 0x6550 0x6550 0x6554 0x6554 0x6558 0x6558 0x655c 0x655c
[  104.705582] [drm]   Encoders:
[  104.705583] [drm]     DFP2: INTERNAL_UNIPHY
[  104.982448] [drm] fb mappable at 0xC03DA000
[  104.982450] [drm] vram apper at 0xC0000000
[  104.982450] [drm] size 5242880
[  104.982450] [drm] fb depth is 24
[  104.982451] [drm]    pitch is 5120
[  104.982850] fbcon: radeondrmfb (fb0) is primary device
[  105.062208] Console: switching to colour frame buffer device 160x64
[  105.064201] radeon 0000:00:01.0: fb0: radeondrmfb frame buffer device
[  105.076659] [drm] Initialized radeon 2.50.0 20080528 for 0000:00:01.0 on minor 0
[  105.076855] initcall radeon_init+0x0/0xb0 [radeon] returned 0 after 2139213 usecs
[…]
$ sudo lspci -vvxxx -s 0:01.0
00:01.0 VGA compatible controller: Advanced Micro Devices, Inc. [AMD/ATI] Richland [Radeon HD 8470D] (prog-if 00 [VGA controller])
	Subsystem: ASUSTeK Computer Inc. Richland [Radeon HD 8470D]
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 44
	Region 0: Memory at c0000000 (32-bit, prefetchable) [size=256M]
	Region 1: I/O ports at f000 [size=256]
	Region 2: Memory at feb00000 (32-bit, non-prefetchable) [size=256K]
	[virtual] Expansion ROM at 000c0000 [disabled] [size=128K]
	Capabilities: [50] Power Management version 3
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
		Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [58] Express (v2) Root Complex Integrated Endpoint, MSI 00
		DevCap:	MaxPayload 128 bytes, PhantFunc 0
			ExtTag+ RBE+
		DevCtl:	Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
			RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+
			MaxPayload 128 bytes, MaxReadReq 128 bytes
		DevSta:	CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr- TransPend-
		DevCap2: Completion Timeout: Not Supported, TimeoutDis-, LTR-, OBFF Not Supported
		DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
	Capabilities: [a0] MSI: Enable+ Count=1/1 Maskable- 64bit+
		Address: 00000000fee00000  Data: 0000
	Capabilities: [100 v1] Vendor Specific Information: ID=0001 Rev=1 Len=010 <?>
	Kernel driver in use: radeon
	Kernel modules: radeon
00: 02 10 96 99 07 04 10 00 00 00 00 03 10 00 80 00
10: 08 00 00 c0 01 f0 00 00 00 00 b0 fe 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 43 10 26 85
30: 00 00 00 00 50 00 00 00 00 00 00 00 0a 01 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 43 10 26 85
50: 01 58 03 06 00 00 00 00 10 a0 92 00 a0 8f 00 00
60: 10 09 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 05 00 81 00 00 00 e0 fe 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

```

1.6 seconds are spent in ib tests, and the rest 500 ms are also much too long.
Comment 1 Paul Menzel 2018-06-17 08:18:06 UTC 
Just to put this into perspective, that without loading the radeon module, the OS, that means Linux kernel + user space, takes around two to three seconds to start (substracting the LUKS passphrase dialog).
Comment 2 Paul Menzel 2018-06-17 08:18:44 UTC 
Is that a firmware or hardware problem?
Comment 3 Christian König 2018-06-18 10:59:55 UTC 
That is expected behavior.

Because of stability issues we don't enable power management during startup initially which makes the hardware run at it's default clock (usually between 17 and 100MHz) during startup.
Comment 4 Paul Menzel 2018-06-18 11:10:15 UTC 
Is there a switch to override that behavior?
Comment 5 Christian König 2018-06-18 11:28:08 UTC 
(In reply to Paul Menzel from comment #4)
> Is there a switch to override that behavior?

Long story short, no there isn't.

You could try to disable certain blocks with radeon.uvd=0 and radeon.vce=0 to speed up boot a bit if you don't need that functionality.

But that's basically all you can do without implementing a different approach to power management.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.