Bug 102203 - Using hardware video encoding with amdgpu/vaapi crashes system immediately
Summary: Using hardware video encoding with amdgpu/vaapi crashes system immediately
Status: RESOLVED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/AMDgpu (show other bugs)
Version: DRI git
Hardware: x86-64 (AMD64) Linux (All)
: medium normal
Assignee: Default DRI bug account
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-08-13 22:04 UTC by dwagner
Modified: 2017-08-17 21:59 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:


Attachments

Description dwagner 2017-08-13 22:04:40 UTC
I tried using hardware video encoding with amdgpu/vaapi, but every attempt immediately crashes the system.

The latest command line (amongst many with the same crash result) I tried:

ffmpeg -vaapi_device /dev/dri/renderD128 -t 10 -i somevideo.mp4 -vf 'scale=1920:1072,hwupload' -aspect 1920:1072 -map 0:0 -y -c:a copy -threads 1 -slices 1 -vcodec h264_vaapi -b:v 12500k -profile:v 77 -bf 0 test.mkv

ffmpeg/libva/mesa/dri etc. are the most recent ones currently shipped with Arch Linux (ffmpeg version 3.3.3 built with gcc 7.1.1).

I am currently using https://cgit.freedesktop.org/~agd5f/linux/log/?h=amd-staging-drm-next as my kernel, but experienced the same error also with previous kernel versions (like 4.12)

Video card is a Radeon RX 460.
Comment 1 Michel Dänzer 2017-08-14 07:01:26 UTC
Please attach the output of dmesg and vainfo.
Comment 2 dwagner 2017-08-14 15:38:31 UTC
The output of vainfo:

libva info: VA-API version 0.40.0
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib/dri/radeonsi_drv_video.so
libva info: Found init function __vaDriverInit_0_40
libva info: va_openDriver() returns 0
vainfo: VA-API version: 0.40 (libva )
vainfo: Driver version: mesa gallium vaapi
vainfo: Supported profile and entrypoints
      VAProfileMPEG2Simple            : VAEntrypointVLD
      VAProfileMPEG2Main              : VAEntrypointVLD
      VAProfileVC1Simple              : VAEntrypointVLD
      VAProfileVC1Main                : VAEntrypointVLD
      VAProfileVC1Advanced            : VAEntrypointVLD
      VAProfileH264ConstrainedBaseline: VAEntrypointVLD
      VAProfileH264ConstrainedBaseline: VAEntrypointEncSlice
      VAProfileH264Main               : VAEntrypointVLD
      VAProfileH264Main               : VAEntrypointEncSlice
      VAProfileH264High               : VAEntrypointVLD
      VAProfileH264High               : VAEntrypointEncSlice
      VAProfileHEVCMain               : VAEntrypointVLD
      VAProfileHEVCMain10             : VAEntrypointVLD
      VAProfileNone                   : VAEntrypointVideoProc


"dmesg -w" output (starting from a moment before the "ffmpeg" command was issued) - this output I catched by re-directing "dmesg -w" to a network file system - it might be incomplete due to the system becoming completely unresponsive (and the screen going black) right after starting "ffmpeg":

[ 2148.882511] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.882517] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.882519] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.882522] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.883867] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.883872] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.883874] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.883877] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.884468] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.884471] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.884473] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.884476] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.885617] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.885619] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.885620] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.885623] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.886758] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.886761] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.886762] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.886764] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.887899] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.887901] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.887902] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.887903] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.889041] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.889044] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.889045] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.889047] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.890182] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.890185] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.890186] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.890188] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.891324] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.891326] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.891327] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.891328] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2148.902478] amdgpu 0000:28:00.0: GPU fault detected: 146 0x0c283e0c
[ 2148.902481] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_ADDR   0x00100985
[ 2148.902483] amdgpu 0000:28:00.0:   VM_CONTEXT1_PROTECTION_FAULT_STATUS 0x0603E00C
[ 2148.902485] amdgpu 0000:28:00.0: VM fault (0x0c, vmid 3) at page 1051013, read from 'VCE0' (0x56434530) (62)
[ 2153.014359] [drm:amdgpu_job_timedout [amdgpu]] *ERROR* ring vce0 timeout, last signaled seq=6, last emitted seq=8
[ 2153.014366] [drm] IP block:gmc_v8_0 is hung!
[ 2153.014477] [drm] IP block:vce_v3_0 is hung!
[ 2153.014544] [drm] Atomic commit: RESET. crtc id 0:[ffff8807f5490000]
[ 2153.014547] [drm] dc_commit_context: 0 streams
[ 2153.051207] [drm] Some block need full reset!
[ 2153.051856] [drm:amdgpu_suspend [amdgpu]] *ERROR* suspend of IP block <vce_v3_0> failed -22
[ 2153.154613] amdgpu 0000:28:00.0: GPU pci config reset
[ 2153.607900] amdgpu 0000:28:00.0: GPU reset succeeded, trying to resume
[ 2153.607996] [drm] PCIE GART of 256M enabled (table at 0x000000F400040000).
[ 2153.608033] [drm:amdgpu_gpu_reset [amdgpu]] *ERROR* VRAM is lost!
[ 2153.610052] amdgpu: [powerplay] DPM is already running
[ 2153.612868] amdgpu: [powerplay] 
                failed to send message 309 ret is 254 
[ 2153.612893] amdgpu: [powerplay] 
                failed to send pre message 14e ret is 254 
[ 2153.622583] [drm] ring test on 0 succeeded in 9 usecs
[ 2153.622840] [drm] ring test on 9 succeeded in 4 usecs
[ 2153.622971] [drm] ring test on 1 succeeded in 57 usecs
[ 2153.623011] [drm] ring test on 2 succeeded in 17 usecs
[ 2153.623050] [drm] ring test on 3 succeeded in 16 usecs
[ 2153.623091] [drm] ring test on 4 succeeded in 17 usecs
[ 2153.623109] [drm] ring test on 5 succeeded in 7 usecs
[ 2153.623125] [drm] ring test on 6 succeeded in 6 usecs
[ 2153.623142] [drm] ring test on 7 succeeded in 6 usecs
[ 2153.623160] [drm] ring test on 8 succeeded in 7 usecs
[ 2153.623221] [drm] ring test on 10 succeeded in 3 usecs
[ 2153.623227] [drm] ring test on 11 succeeded in 3 usecs
[ 2153.649576] [drm] ring test on 12 succeeded in 1 usecs
[ 2153.649577] [drm] UVD initialized successfully.
[ 2153.759533] [drm] ring test on 13 succeeded in 0 usecs
[ 2153.759562] [drm] ring test on 14 succeeded in 9 usecs
[ 2153.759562] [drm] VCE initialized successfully.
[ 2153.759603] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.759636] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.759677] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.759708] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.759738] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.759777] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.759806] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.759836] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.759874] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.759903] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.759932] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.759970] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.759998] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.760027] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.760065] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.760093] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_ack: called for non-implemented irq source
[ 2153.760122] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_dummy_set: called for non-implemented irq source
[ 2153.760159] [drm:amdgpu_dm_set_pflip_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_pflip_irq_state: crtc is NULL at id :5
[ 2153.760403] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.760432] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760463] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760492] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760521] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.760550] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.760800] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.760831] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760862] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760890] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.760920] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.760952] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.761198] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.761227] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761258] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761287] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761316] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.761346] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.761590] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.761619] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761651] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761680] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.761709] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.761739] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.761985] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.762016] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762047] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762075] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762104] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.762133] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.762379] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :5
[ 2153.762408] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762438] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762467] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -30635
[ 2153.762495] [drm:log_to_debug_console [amdgpu]] *ERROR* dal_irq_service_set: cannot find irq info table entry for -5554
[ 2153.762525] [drm:amdgpu_dm_set_crtc_irq_state [amdgpu]] *ERROR* amdgpu_dm_set_crtc_irq_state: crtc is NULL at id :11
[ 2153.763003] [drm] ib test on ring 0 succeeded
[ 2153.763099] [drm] ib test on ring 1 succeeded
[ 2153.763133] [drm] ib test on ring 2 succeeded
[ 2153.763160] [drm] ib test on ring 3 succeeded
[ 2153.763188] [drm] ib test on ring 4 succeeded
[ 2153.763215] [drm] ib test on ring 5 succeeded
[ 2153.763243] [drm] ib test on ring 6 succeeded
[ 2153.763270] [drm] ib test on ring 7 succeeded
[ 2153.763297] [drm] ib test on ring 8 succeeded
[ 2154.267705] [drm] ib test on ring 9 succeeded
[ 2154.267760] [drm] ib test on ring 10 succeeded
[ 2154.267778] [drm] ib test on ring 11 succeeded
[ 2154.269431] [drm] ib test on ring 12 succeeded
[ 2154.269682] [drm] ib test on ring 13 succeeded
[ 2154.269683] [drm] recover vram bo from shadow
[ 2154.270114] [drm:amdgpu_job_run [amdgpu]] *ERROR* Skip scheduling IBs!
[ 2154.270170] [drm:amdgpu_job_run [amdgpu]] *ERROR* Skip scheduling IBs!
[ 2154.270225] [drm:amd_sched_job_recovery [amdgpu]] *ERROR* Failed to run job!
[ 2154.270274] [drm:amd_sched_main [amdgpu]] *ERROR* Failed to run job!
[ 2154.270326] [drm:amdgpu_job_run [amdgpu]] *ERROR* Skip scheduling IBs!
[ 2154.270367] [drm:amd_sched_main [amdgpu]] *ERROR* Failed to run job!
[ 2154.270730] [drm] Atomic commit: SET crtc id 0: [ffff8807f5490000]
[ 2154.270733] [drm] dc_commit_context: 1 streams
[ 2154.270736] [drm] core_stream 0xe1575c00: src: 0, 0, 3840, 2160; dst: 0, 0, 3840, 2160, colorSpace:4
[ 2154.270738] [drm] 	pix_clk_khz: 594000, h_total: 4400, v_total: 2250, pixelencoder:3, displaycolorDepth:2
[ 2154.270740] [drm] 	sink name: LG TV, serial: 16843012
[ 2154.270741] [drm] 	link: 1
[ 2154.270801] [drm] dce_get_required_clocks_state: clocks unsupported
[ 2154.273989] [drm] [Mode]	[HDMIA][ConnIdx:1] {3840x2160, 4400x2250@594000Khz}^
[ 2154.287836] [drm] link=0, dc_sink_in=          (null) is now Disconnected
[ 2154.287838] [drm] DCHPD: connector_id=0: dc_sink didn't change.
[ 2154.312514] [drm] [Detect]	[HDMIA][ConnIdx:1] LG TV: [Block 0] 00 FF FF FF FF FF FF 00 1E 6D 01 00 01 01 01 01 01 19 01 03 80 A0 5A 78 0A EE 91 A3 54 4C 99 26 0F 50 54 A1 08 00 31 40 45 40 61 40 71 40 81 80 01 01 01 01 01 01 08 E8 00 30 F2 70 5A 80 B0 58 8A 00 40 84 63 00 00 1E 02 3A 80 18 71 38 2D 40 58 2C 45 00 40 84 63 00 00 1E 00 00 00 FD 00 3A 3E 1E 88 3C 00 0A 20 20 20 20 20 20 00 00 00 FC 00 4C 47 20 54 56 0A 20 20 20 20 20 20 20 01 A0 ^
[ 2154.312524] [drm] [Detect]	[HDMIA][ConnIdx:1] LG TV: [Block 1] 02 03 55 F1 58 10 9F 04 13 05 14 03 02 12 20 21 22 15 01 60 61 5D 5E 5F 65 66 62 63 64 29 3D 06 C0 15 07 50 09 57 07 7C 03 0C 00 20 00 B8 3C 20 C0 8E 01 02 03 04 01 4F 3F FC 08 10 18 10 06 10 16 10 28 10 67 D8 5D C4 01 78 80 03 E3 05 C0 00 E4 0F 00 C0 18 66 21 50 B0 51 00 1B 30 40 70 36 00 40 84 63 00 00 1E 01 1D 00 72 51 D0 1E 20 6E 28 55 00 40 84 63 00 00 1E 00 00 00 00 00 00 8E ^
[ 2154.312526] [drm] dc_link_detect: manufacturer_id = 6D1E, product_id = 1, serial_number = 1010111, manufacture_week = 1, manufacture_year = 25, display_name = LG TV, speaker_flag = 5, audio_mode_count = 3
[ 2154.312527] [drm] dc_link_detect: mode number = 0, format_code = 7, channel_count = 5, sample_rate = 6, sample_size = 192
[ 2154.312527] [drm] dc_link_detect: mode number = 1, format_code = 2, channel_count = 5, sample_rate = 7, sample_size = 80
[ 2154.312528] [drm] dc_link_detect: mode number = 2, format_code = 1, channel_count = 1, sample_rate = 87, sample_size = 7
[ 2154.312529] [drm] link=1, dc_sink_in=ffff8807e1576400 is now Connected
[ 2154.312530] [drm] DCHPD: connector_id=1: Old sink=          (null) New sink=ffff8807e1576400
[ 2154.312543] [drm] link=2, dc_sink_in=          (null) is now Disconnected
[ 2154.312544] [drm] DCHPD: connector_id=2: dc_sink didn't change.
[ 2154.312569] [drm] Atomic commit: RESET. crtc id 0:[ffff8807f5490000]
[ 2154.312570] [drm] Atomic commit: RESET. crtc id 1:[ffff8807f5491000]
[ 2154.312570] [drm] Atomic commit: RESET. crtc id 2:[ffff8807f5496000]
[ 2154.312571] [drm] Atomic commit: RESET. crtc id 3:[ffff8807f5493000]
[ 2154.312571] [drm] Atomic commit: RESET. crtc id 4:[ffff8807f5497000]
[ 2154.312589] amdgpu 0000:28:00.0: GPU reset successed!
[ 2154.316621] [drm] Atomic commit: SET crtc id 0: [ffff8807f5490000]
[ 2154.316624] [drm] dc_commit_context: 1 streams
[ 2154.316626] [drm] core_stream 0xd82d6800: src: 0, 0, 1024, 768; dst: 0, 0, 1024, 768, colorSpace:4
[ 2154.316627] [drm] 	pix_clk_khz: 65000, h_total: 1344, v_total: 806, pixelencoder:3, displaycolorDepth:2
[ 2154.316628] [drm] 	sink name: LG TV, serial: 16843012
[ 2154.316629] [drm] 	link: 1
[ 2154.360089] [drm] [Mode]	[HDMIA][ConnIdx:1] {1024x768, 1344x806@65000Khz}^
[ 2154.400850] show_signal_msg: 3297 callbacks suppressed
[ 2154.400852] ffmpeg[1009]: segfault at 4 ip 00007fb71c9a8eca sp 00007ffe88744568 error 6 in radeonsi_drv_video.so[7fb71c669000+41d000]
[ 2154.414187] [CRTC:42:crtc-0] vblank wait timed out
[ 2154.414220] ------------[ cut here ]------------
[ 2154.414228] WARNING: CPU: 4 PID: 809 at drivers/gpu/drm/drm_atomic_helper.c:1244 drm_atomic_helper_wait_for_vblanks.part.7+0x263/0x270 [drm_kms_helper]
[ 2154.414228] Modules linked in: arc4 md4 nls_utf8 cifs ccm dns_resolver fscache joydev mousedev hid_generic hidp hid ipt_REJECT nf_reject_ipv4 nf_log_ipv4 nf_log_common xt_LOG xt_tcpudp xt_owner xt_mark iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 cmac nf_nat nf_conntrack bnep cpufreq_ondemand iptable_mangle msr iptable_filter nls_iso8859_1 nls_cp437 vfat fat btusb btrtl btbcm snd_hda_codec_realtek btintel edac_mce_amd snd_hda_codec_generic bluetooth kvm_amd igb snd_hda_codec_hdmi ecdh_generic kvm snd_hda_intel irqbypass evdev rfkill input_leds crc16 pcspkr snd_hda_codec led_class ptp pps_core dca snd_hda_core snd_hwdep snd_pcm snd_timer snd sp5100_tco soundcore i2c_piix4 tpm_tis shpchp tpm_tis_core tpm 8250_dw button acpi_cpufreq sch_fq_codel usbip_host usbip_core sg exfat(O) it87(O)
[ 2154.414251]  hwmon_vid ip_tables x_tables algif_skcipher af_alg sd_mod uas usb_storage serio_raw atkbd libps2 crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd glue_helper cryptd ccp rng_core ahci libahci xhci_pci libata xhci_hcd usbcore scsi_mod usb_common i8042 serio amdgpu i2c_algo_bit ttm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm xfs libcrc32c crc32c_generic crc32c_intel dm_crypt dm_mod dax nvme nvme_core i2c_dev
[ 2154.414266] CPU: 4 PID: 809 Comm: Xorg Tainted: G        W  O    4.13.0-rc2-amd+ #1
[ 2154.414267] Hardware name: System manufacturer System Product Name/PRIME X370-PRO, BIOS 0805 06/20/2017
[ 2154.414268] task: ffff8807f9228000 task.stack: ffffc90003ebc000
[ 2154.414273] RIP: 0010:drm_atomic_helper_wait_for_vblanks.part.7+0x263/0x270 [drm_kms_helper]
[ 2154.414274] RSP: 0018:ffffc90003ebf7d8 EFLAGS: 00010286
[ 2154.414274] RAX: 0000000000000026 RBX: 0000000000000000 RCX: 0000000000000001
[ 2154.414275] RDX: 0000000000000000 RSI: 0000000000000002 RDI: ffffffff81c4ef40
[ 2154.414276] RBP: ffffc90003ebf848 R08: 0000000000000000 R09: 0000000000000026
[ 2154.414276] R10: ffffc90003ebf7d8 R11: 0000000000000513 R12: ffff8807faeaa800
[ 2154.414277] R13: 0000000000000000 R14: 0000000000000000 R15: ffff8807f5490000
[ 2154.414278] FS:  00007f1788115940(0000) GS:ffff88081ed00000(0000) knlGS:0000000000000000
[ 2154.414278] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2154.414279] CR2: 00000082242a2f08 CR3: 00000007f8ad8000 CR4: 00000000003406e0
[ 2154.414279] Call Trace:
[ 2154.414284]  ? wait_woken+0x80/0x80
[ 2154.414289]  drm_atomic_helper_wait_for_vblanks+0x14/0x20 [drm_kms_helper]
[ 2154.414333]  amdgpu_dm_atomic_commit_tail+0x799/0xa40 [amdgpu]
[ 2154.414339]  ? drm_atomic_helper_wait_for_dependencies+0x68/0x160 [drm_kms_helper]
[ 2154.414344]  commit_tail+0x3f/0x60 [drm_kms_helper]
[ 2154.414348]  drm_atomic_helper_commit+0x106/0x110 [drm_kms_helper]
[ 2154.414389]  amdgpu_dm_atomic_commit+0x90/0xa0 [amdgpu]
[ 2154.414401]  drm_atomic_commit+0x4b/0x50 [drm]
[ 2154.414406]  restore_fbdev_mode_atomic+0x17f/0x1e0 [drm_kms_helper]
[ 2154.414410]  drm_fb_helper_restore_fbdev_mode_unlocked.part.22+0x44/0x190 [drm_kms_helper]
[ 2154.414415]  drm_fb_helper_set_par+0x43/0x70 [drm_kms_helper]
[ 2154.414417]  fb_set_var+0x193/0x430
[ 2154.414448]  ? amdgpu_vm_bo_update_mapping+0x393/0x3e0 [amdgpu]
[ 2154.414450]  ? reservation_object_reserve_shared+0x64/0x80
[ 2154.414453]  fbcon_blank+0x206/0x390
[ 2154.414456]  do_unblank_screen+0xb4/0x1a0
[ 2154.414457]  vt_ioctl+0x4e1/0x11b0
[ 2154.414465]  ? drm_gem_handle_create+0x40/0x40 [drm]
[ 2154.414467]  tty_ioctl+0x3cc/0x870
[ 2154.414470]  do_vfs_ioctl+0xa5/0x600
[ 2154.414472]  ? vfs_write+0x134/0x1a0
[ 2154.414473]  SyS_ioctl+0x79/0x90
[ 2154.414476]  entry_SYSCALL_64_fastpath+0x13/0x94
[ 2154.414477] RIP: 0033:0x7f1785a1e8b7
[ 2154.414478] RSP: 002b:00007ffca3b422b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 2154.414479] RAX: ffffffffffffffda RBX: 00000000027f6b90 RCX: 00007f1785a1e8b7
[ 2154.414479] RDX: 0000000000000000 RSI: 0000000000004b3a RDI: 000000000000000a
[ 2154.414480] RBP: 00000000027f6c00 R08: 0000000000000001 R09: 00007ffca3b42060
[ 2154.414480] R10: 0000000000000000 R11: 0000000000000246 R12: 00000000028f3b30
[ 2154.414481] R13: 00000000028e4830 R14: 00000000028e5648 R15: 00000000028e57b8
[ 2154.414482] Code: 03 b8 88 01 00 00 48 83 c7 08 e8 19 ef e0 e0 85 db 0f 85 c9 fe ff ff 49 8b 57 20 41 8b 77 60 48 c7 c7 c8 0d 2a a0 e8 ae 45 e2 e0 <0f> ff e9 ae fe ff ff 66 0f 1f 44 00 00 0f 1f 44 00 00 f6 46 10 
[ 2154.414499] ---[ end trace 1224ee5fc3c4708e ]---
Comment 3 Andy Furniss 2017-08-15 22:54:24 UTC
Does it help if you set the env

VAAPI_DISABLE_INTERLACE=1

and modify the -vf to look like

-vf 'scale=1920:1072,format=nv12|vaapi,hwupload'

Without those I don't crash on R9 285, but the result would be junk - so worth using!

1072 is a strange height to use though it doesn't hurt my setup.
Comment 4 dwagner 2017-08-17 20:23:32 UTC
(In reply to Andy Furniss from comment #3)
> Does it help if you set the env
> 
> VAAPI_DISABLE_INTERLACE=1

Yes! I wonder how "interlace" is still a thing so many years after CRTs became obsolete, and no interlaced videos were ever involved in my attempts, but whatever this variable does, it changed the hardware encoding experience for me from "crashes all the time" to "does not crash and even produces a proper video in about 50% of invocations".

Weirdly, about half of the times I start the very same ffmpeg command line for the very same input file, the output video shows mixed up positions of frames, as in "not frames 1-2-3-4-5-6 but e.g. 1-4-2-3-5-6 shown in sequence".

> and modify the -vf to look like
> 
> -vf 'scale=1920:1072,format=nv12|vaapi,hwupload'

Works for me as well as my original command line.

> 1072 is a strange height to use though it doesn't hurt my setup.

At one point in time, I got error messages from ffmpeg that the encoder was incompatible with sizes that are not even multiples of 16 - that's why I introduced this scaling just for testing. But this scaling is not relevant anymore, works the same now with or without it.

I think we can close this bug report: While the distorted-frame-sequence-half-the-times symptom is unpleasant, it's quite different from "crashing all the time". 

And now that I experienced that h.264 hardware encoding on an RX 460 (in 4k) does not even reach realtime speed, it seems to me that I should probably stick to "x264 -preset ultrafast" for live streaming anyway.
Comment 5 Andy Furniss 2017-08-17 21:59:06 UTC
VCE does seen to have suffered some regressions recently - I stopped testing it in March due to one in mesa that broke my normal testing.
It's possible that gstreamer regressed and the mesa commit just exposed its deficiencies.
Whatever the reason there are more issues now and I don't know what caused them or when they started due to ignoring VCE for so long.
ffmpeg was OK last time I tried - but it clearly isn't for you.

On the 4K speed - even when everything was working perfectly ffmpeg always was half the speed of gstreamer for me. I could in a very artificial test get 4K60p encode with gstreamer (pre-prepared raw nv12 video in ram). Getting that speed in other circumstances gets tricky as CPU bottlenecks get involved for things like making the nv12 from other formats to feed the encoder.


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.