| Bug ID | 109022 |
|---|---|
| Summary | ring gfx timeout during particular shader generation on yuzu = emulator |
| Product | Mesa |
| Version | 18.3 |
| Hardware | x86-64 (AMD64) |
| OS | Linux (All) |
| Status | NEW |
| Severity | major |
| Priority | medium |
| Component | Drivers/Gallium/radeonsi |
| Assignee | dri-devel@lists.freedesktop.org |
| Reporter | felix.adrianto@gmail.com |
| QA Contact | dri-devel@lists.freedesktop.org |
How to reproduce the issue? 1. Using yuzu emualtor latest canary build. 2. Load Super Mario Odyssey. 3. Create a new game. 4. Wait until Mario jumps for the first time after being woken up by Cappy.= =20 5. Graphic crashes but system is still accessible through SSH Error message: [ 540.189992] amdgpu 0000:23:00.0: GPU fault detected: 147 0x09088402 for process glretrace pid 2006 thread glretrace:cs0 pid 2007 [ 540.190000] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_ADDR=20= =20 0x00001121 [ 540.190004] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0E084002 [ 540.190010] amdgpu 0000:23:00.0: VM fault (0x02, vmid 7, pasid 32771) at page 4385, read from 'TC7' (0x54433700) (132) [ 550.275970] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, signaled seq=3D20845, emitted seq=3D20848 System specification: AMD Ryzen 5 2600 ASRock B540M with latest bios update 16 GB DDR4 RAM MSI RX580 Gaming X Debian Sid=20 Kernel 4.20-rc6 Mesa 18.3.1 This bug occurs in all combinations of kernel 4.17, 4.18, 4.19, 4.20, drm-next-4.2.1-wip with mesa 18.2, 18.3, 19.0-development I am able to get the apitrace result. It can be downloaded from my google drive. https://drive.google.com/file/d/1MdR1c2g0pQ8ToTCAH53J= c9BUd3WFzbcg/view?usp=3Dsharing The bug can be easily reproduced by replaying the apitrace result very consistently.
A revision of my initial comment. I was able to reproduce the = bug once while replaying the trace and generated the same error in the dmesg output but I = am no longer able to reproduce the error while replaying the trace currently w= hich is very odd.
Out of 10 times replaying the trace, I was able to reproduce t= he bug twice.=20 [ 540.189992] amdgpu 0000:23:00.0: GPU fault detected: 147 0x09088402 for process glretrace pid 2006 thread glretrace:cs0 pid 2007 [ 540.190000] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_ADDR=20= =20 0x00001121 [ 540.190004] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0E084002 [ 540.190010] amdgpu 0000:23:00.0: VM fault (0x02, vmid 7, pasid 32771) at page 4385, read from 'TC7' (0x54433700) (132) [ 550.275970] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, signaled seq=3D20845, emitted seq=3D20848 The error message from dmesg is identical when producing the bug from apitr= ace.
I did a little more troubleshooting on my API trace.=20 Call #36840880 is the culprit of the VMC Page Fault error. The GPU didn't c= rash right away but continuing 100-200 calls after 36840880 might randomly trigg= er the ring gfx timeout error.
Created attachment 142865 =
[details]
freeze-screenshot
Created attachment 142866 [details]<=
/span>
dmesg
Same pb here on a r9 fury, mesa 18.3 Complete freeze on various games in yuzu (easy to reproduce: super mario odissey). I attached a screenshot + the dmesg log obtained via ssh.
I can reproduce the error during the FMV as well. You can quic= kly bypass this FMV by skipping it before the error occurs (I couldn't remember how to trig= ger the skipping selection on your screen). I am wondering if you would get the same crash too when Mario was about to jump for the first time after being woken up by cappy?
Hi,=20 This bug still occurs with kernel 5.0-rc4 with Mesa 19.0-devel (commit 932ed9c00b99e6ec92146ec9e820f546cf3e6551). There are more error logs in dme= sg like below. [ 1132.040752] amdgpu 0000:23:00.0: GPU fault detected: 147 0x0a808802 for process yuzu pid 19573 thread yuzu:cs0 pid 19577 [ 1132.040761] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_ADDR=20= =20 0x0003F350 [ 1132.040766] amdgpu 0000:23:00.0: VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0C088002 [ 1132.040773] amdgpu 0000:23:00.0: VM fault (0x02, vmid 6, pasid 32770) at page 258896, read from 'TC6' (0x54433600) (136) [ 1142.103758] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, signaled seq=3D50481, emitted seq=3D50484 [ 1142.103820] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* Process informati= on: process yuzu pid 19573 thread yuzu:cs0 pid 19577 [ 1142.103826] amdgpu 0000:23:00.0: GPU reset begin! [ 1149.487464] WARNING: CPU: 9 PID: 19117 at kernel/kthread.c:501 kthread_park+0x20/0x67 [ 1149.487467] Modules linked in: hid_switchcon hidp tda18271 s5h1411 rfcomm fuse cmac bnep binfmt_misc amdgpu mfd_core kvm irqbypass ghash_clmulni_intel btusb btrtl btbcm btintel bluetooth snd_hda_codec_realtek snd_hda_codec_gen= eric snd_usb_audio snd_usbmidi_lib snd_hda_codec_hdmi sha256_generic snd_rawmidi snd_pcsp chash gpu_sched saa7164 xpad snd_hda_intel tveeprom drm_kms_helper joydev evdev aesni_intel syscopyarea dvb_core sysfillrect snd_hda_codec sysimgblt fb_sys_fops aes_x86_64 snd_hwdep ttm crypto_simd snd_hda_core cry= ptd ff_memless drbg glue_helper snd_pcm drm snd_timer i2c_algo_bit videodev snd ecdh_generic sp5100_tco soundcore k10temp media sg 8250 8250_base serial_co= re button acpi_cpufreq nct6775 hwmon_vid autofs4 ext4 crc16 mbcache jbd2 sd_mod hid_generic usbhid hid i2c_piix4 ahci xhci_pci crc32c_intel i2c_core libahci xhci_hcd r8169 libata realtek libphy usbcore scsi_mod usb_common [ 1149.487525] CPU: 9 PID: 19117 Comm: MemoryInfra Not tainted 5.0.0-rc4-ht= pc+ #3 [ 1149.487526] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./B450M Pro4, BIOS P2.00 12/18/2018 [ 1149.487530] RIP: 0010:kthread_park+0x20/0x67 [ 1149.487533] Code: e8 09 ff ff ff 48 89 c7 eb 8f 55 53 e8 fd fe ff ff f6 = 47 24 04 74 09 0f 0b b8 da ff ff ff eb 4e 48 89 c3 48 8b 00 a8 04 74 09 <0f= > 0b b8 f0 ff ff ff eb 3b 48 89 fd f0 80 0b 04 65 48 8b 04 25 40 [ 1149.487534] RSP: 0018:ffffc900030d7bc0 EFLAGS: 00010202 [ 1149.487537] RAX: 0000000000000004 RBX: ffff88840868f680 RCX: 0000000000000000 [ 1149.487538] RDX: ffff8883d0794330 RSI: ffff88827243f330 RDI: ffff88840732ee80 [ 1149.487540] RBP: ffff888407ad7398 R08: 0000000000000001 R09: ffff888288facd80 [ 1149.487541] R10: 0000000000000040 R11: ffffc900030d7bc0 R12: 000000000000000d [ 1149.487543] R13: 0000000000000006 R14: ffff88840b01d000 R15: ffff88840b01d0f0 [ 1149.487545] FS: 00007f96304a6700(0000) GS:ffff88841ee40000(0000) knlGS:0000000000000000 [ 1149.487547] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1149.487548] CR2: 00007f229032b000 CR3: 0000000407b90000 CR4: 00000000003406e0 [ 1149.487549] Call Trace: [ 1149.487559] drm_sched_entity_fini+0x4c/0xeb [gpu_sched] [ 1149.487612] amdgpu_ctx_mgr_entity_fini+0x80/0xa8 [amdgpu] [ 1149.487662] amdgpu_ctx_mgr_fini+0x22/0x8b [amdgpu] [ 1149.487706] amdgpu_driver_postclose_kms+0x188/0x242 [amdgpu] [ 1149.487717] drm_file_free+0x1e6/0x22d [drm] [ 1149.487728] drm_release+0x75/0xdf [drm] [ 1149.487733] __fput+0xe9/0x18f [ 1149.487737] task_work_run+0x68/0x7c [ 1149.487741] do_exit+0x450/0x917 [ 1149.487744] do_group_exit+0x95/0x95 [ 1149.487748] get_signal+0x439/0x461 [ 1149.487752] do_signal+0x31/0x4cc [ 1149.487757] prepare_exit_to_usermode+0x8b/0xf5 [ 1149.487762] entry_SYSCALL_64_after_hwframe+0x44/0xa9 [ 1149.487764] RIP: 0033:0x7f964651ffac [ 1149.487772] Code: Bad RIP value. [ 1149.487773] RSP: 002b:00007f96304a5640 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca [ 1149.487776] RAX: fffffffffffffe00 RBX: 00007f96304a57b0 RCX: 00007f964651ffac [ 1149.487777] RDX: 0000000000000000 RSI: 0000000000000080 RDI: 00007f96304a57d8 [ 1149.487778] RBP: 0000000000000000 R08: 0000000000000000 R09: 00007fff49705080 [ 1149.487779] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 [ 1149.487781] R13: 00007f96304a5788 R14: 0000000000000000 R15: 00007f96304a57d8 [ 1149.487784] ---[ end trace 540c7632a8289097 ]--- [ 1152.333861] [drm:amdgpu_dm_atomic_check [amdgpu]] *ERROR* [CRTC:47:crtc-= 0] hw_done or flip_done timed out If you need more clarification or detail, please let me know.
I tried to enable NIR using R600_DEBUG=3Dnir, I got a differen= t behaviour on GFX timeout.=20 [Feb 1 19:44] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240122] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [Feb 1 19:45] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240145] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240170] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.239953] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240061] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240340] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [Feb 1 19:46] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240003] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240173] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240074] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.239890] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [Feb 1 19:44] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240122] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [Feb 1 19:45] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240145] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240170] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.239953] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240061] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240340] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [Feb 1 19:46] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240003] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240173] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered [ +10.240074] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout, = but soft recovered I get a a looping error message like the above but I can kill the applicati= on from ssh. Display is once again usable, no hard reset is required.
| What | Removed | Added |
|---|---|---|
| CC | saliksaeed@ymail.com |
*** Bug 109870 has been marked as a du= plicate of this bug. ***
I usually build mesa master weekly since November 2018. This b= ug can be reproduced with latest Mesa from git master branch.=20 Do you want me to try to build 18.3.5 and reproduce it?
(In reply to e88z4 from comment #12) > I usually build mesa master weekly since Novembe= r 2018. This bug can be > reproduced with latest Mesa from git master branch.=20 >=20 > Do you want me to try to build 18.3.5 and reproduce it? No, I was just curious if the bug showed up in 18.3.5.
I tried to reproduce this bug again with latest mesa master (6= 59aa3dd651). My kernel is 5.1.3 and yuzu-canary #2318. The behaviour of the softlock is slightly changed. Yuzu didn't crash anymore but rendering was super slow. I= was able to kill the application without using SSH. The following error was produced from dmesg. [ 5179.131132] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5183.739102] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5189.883024] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5193.979037] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5204.218939] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5214.458837] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5224.698730] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5229.818653] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5234.938622] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5234.938680] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5241.850516] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5245.178534] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered [ 5251.322426] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Waiting = for fences timed out. [ 5255.418427] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx timeout,= but soft recovered
(In reply to Timothy Arceri from comment #15) > Maybe related to 110472 Sorry to bug #110472
(In reply to Timothy Arceri from comment #16) > (In reply to Timothy Arceri from comment #15) > > Maybe related to 110472 >=20 > Sorry to bug #110472 It definitely is, as it occurs using the same drivers, exact same program, = and causes the same crash
(In reply to e88z4 from comment #14) > I tried to reproduce this bug again with latest = mesa master (659aa3dd651). > My kernel is 5.1.3 and yuzu-canary #2318. The behaviour of the softloc= k is > slightly changed. Yuzu didn't crash anymore but rendering was super sl= ow. I > was able to kill the application without using SSH. The following erro= r was > produced from dmesg. >=20 > [ 5179.131132] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5183.739102] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5189.883024] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5193.979037] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5204.218939] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5214.458837] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5224.698730] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5229.818653] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5234.938622] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5234.938680] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5241.850516] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5245.178534] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered > [ 5251.322426] [drm:amdgpu_dm_atomic_commit_tail [amdgpu]] *ERROR* Wai= ting > for fences timed out. > [ 5255.418427] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring gfx tim= eout, > but soft recovered Yay, progress
https= ://github.com/yuzu-emu/yuzu/issues/2523 WOOOOOOO! This is getting a Yuzu side fix!
Hi Timothy,=20 I have tried your suggestion on the other bug reporting https://bugs.freedesktop.org/show_bug.= cgi?id=3D110472 You suggested to add an environment variable allow_glsl_extension_directive_midshader=3Dtrue. This doesn't resolve the i= ssue.=20 I also noticed that the yuzu developers followed your suggestion from your = bug reporting ticket h= ttps://github.com/yuzu-emu/yuzu/issues/2523 I decided to compile the latest source code with the merged code but the is= sue is not yet resolved. One thing that I noticed is the "ring fgx timeout= " error message is no longer being produced". Instead error messages below are reproduced continuously until I kill the application.=20 May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: amdgpu_cs_query_fence_status failed. May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: amdgpu_cs_query_fence_status failed. May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:21 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:25 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:25 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. May 27 18:53:29 htpc org.gnome.Shell.desktop[1578]: amdgpu: The CS has been cancelled because the context is lost. I will produce the apitrace shortly and will post it on a share location.
Hi,=20 I uploaded the apitrace in my google drive.=20 https://drive.google.com/file/d/1hg1ep4rJ2Y_g7WmA_Hbm= NndrHd-x7Etc/view?usp=3Dsharing When I replayed the trace, I was able to produce the error.=20 My system is=20 AMD Ryzen 2600 Radeon RX580 Mesa master 659aa3dd651 Kernel 5.1.3 Let me know if you need anything else.
| What | Removed | Added |
|---|---|---|
| Version | 18.3 | git |