GPU accelerated video recording slow unless...

[andres-asm]

given this build: https://files.andressm.org/f/bb6eccb6f91b49d18bb6/ which includes ffmpeg with NVENC and this recording config:

vcodec = h264_nvenc
acodec = libmp3lame
scale_factor = 1

threads = 1
pix_fmt = yuv420p
video_preset = fast
video_profile = baseline
audio_global_quality = 75
format = matroska
level = 5.1
video_qmin = 10
video_qmax = 23
video_bitrate = 2000k
video_maxrate = 4000k

recording will no longer be fast unless you do:

• start recording
• go to settings/video
• toggle threaded video now it's fast again if you start with threaded enabled it doesn't work

This needs windows/nvidia of course

[andres-asm]

I would certainly like it if someone confirmed.

[andres-asm]

I just tested this out, I recorded a full ridge racer race I played the game fullspeed once I toggled the setting the video though, is very badly synced (video and audio drifted a lot) maybe because of the initial slowdown.

https://streamable.com/o13h3

[andres-asm]

Just tried with the vanilla ffmpeg and not-hw enabled recording and it happens too. It's not as fast (ie there are fps drops while in-game) but nowhere near as much as without toggling threaded video.

[orbea]

I can reproduce these issues in Linux too.

[orbea]

It was a bit late last night to add more details, but the issues I can reproduce where the recording config is not needed.

1. Recording causes a major performance lag.
2. Turning off vsync speeds it up a lot, but its still slow.
3. The fps counter while recording is broken and it will be stuck around 60 until I toggle the menu one or more times and it will then become some crazy large number which is clearly not correct.

What I can not reproduce is that threaded video speeds it up, with threaded video and recording RetroArch freezes a moment after resuming content.

Here are also some more clues which seems to indicate the bottleneck is largely CPU bound and in libx264 and a memcpy which may or may not be in RetroArch.

perf top

    32.93%  libx264.so.155         [.] x264_8_trellis_coefn
     7.98%  libc-2.28.so           [.] __memcpy_ssse3
     3.74%  [processor]            [k] init_module
     2.53%  libx264.so.155         [.] x264_8_macroblock_cache_load_prog
     2.05%  libx264.so.155         [.] x264_8_macroblock_cache_save
     1.72%  libswscale.so.5.4.100  [.] 0x0000000000060afe
     1.46%  retroarch              [.] 0x000000000022ce24
     1.28%  libswscale.so.5.4.100  [.] 0x00000000000575e2
     1.25%  libswscale.so.5.4.100  [.] 0x0000000000060af9
     0.97%  [kernel]               [k] deactivate_slab.isra.69
     0.89%  libx264.so.155         [.] x264_8_macroblock_analyse
     0.82%  libx264.so.155         [.] x264_8_me_search_ref
     0.70%  retroarch              [.] 0x000000000022ce33
     0.65%  retroarch              [.] 0x000000000022ce3a
     0.65%  retroarch              [.] 0x000000000022ce20
     0.62%  retroarch              [.] 0x000000000022ce2f
     0.60%  libx264.so.155         [.] x264_8_macroblock_probe_skip
     0.57%  libswscale.so.5.4.100  [.] 0x00000000000559b4
     0.53%  libx264.so.155         [.] x264_8_copy_column8
     0.50%  [kernel]               [k] kernel_poison_pages
     0.50%  libswscale.so.5.4.100  [.] 0x0000000000060af4
     0.49%  libx264.so.155         [.] x264_8_macroblock_encode
     0.49%  libswscale.so.5.4.100  [.] 0x0000000000060acb
     0.49%  libswscale.so.5.4.100  [.] 0x0000000000060ae7
     0.48%  libswscale.so.5.4.100  [.] 0x0000000000060ad4
     0.48%  libswscale.so.5.4.100  [.] 0x0000000000060b0b
     0.47%  libswscale.so.5.4.100  [.] 0x0000000000060ade
     0.47%  libswscale.so.5.4.100  [.] 0x00000000000559b0
     0.43%  libx264.so.155         [.] x264_8_mb_predict_mv_direct16x16
     0.43%  libx264.so.155         [.] x264_8_frame_expand_border_filtered
     0.43%  libswscale.so.5.4.100  [.] 0x0000000000060ac2
     0.41%  libx264.so.155         [.] x264_8_ratecontrol_mb

GALLIUM_HUD

[andres-asm]

On windows toggling threaded while recording is underway doesn't crash and makes recording a lot faster, to the point that you can record while playing even with ppsppp or dolphin (with the aforementioned ffmpeg dlls)

[orbea]

It also freezes when built with the address sanitizer, upon forcing it closed I get these leaks.

$ retroarch
[INFO] [Config]: Loading default config.
[INFO] [Config]: loading config from: (null).
[INFO] Looking for config in: "/home/orbea/.config/retroarch/retroarch.cfg".
Sound buffer size: 4100 (1025 samples)
Map_HiROMMap
[libx264 @ 0x6190000e1f80] using SAR=1/1
[libx264 @ 0x6190000e1f80] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX XOP FMA3 BMI1
[libx264 @ 0x6190000e1f80] profile High 4:4:4 Predictive, level 4.2, 4:4:4 8-bit
[libx264 @ 0x6190000e1f80] 264 - core 155 - H.264/MPEG-4 AVC codec - Copyleft 2003-2018 - http://www.videolan.org/x264.html - options: cabac=1 ref=1 deblock=1:1:1 analyse=0x1:0x1 me=dia subme=1 psy=1 psy_rd=0.40:0.00 mixed_ref=0 me_range=16 chroma_me=1 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=6 threads=2 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=5 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=1 keyint=250 keyint_min=25 scenecut=40 intra_refresh=0 rc=crf mbtree=0 crf=15.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 ip_ratio=1.40 pb_ratio=1.30 aq=1:0.60
[matroska @ 0x61b0000e9380] Using AVStream.codec to pass codec parameters to muxers is deprecated, use AVStream.codecpar instead.
[matroska @ 0x61b0000e9380] Using AVStream.codec to pass codec parameters to muxers is deprecated, use AVStream.codecpar instead.
XIO:  fatal IO error 11 (Resource temporarily unavailable) on X server ":0.0"
      after 2082 requests (2082 known processed) with 0 events remaining.
^C
=================================================================
==5437==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 2112 byte(s) in 2 object(s) allocated from:
    #0 0x7fd6e4841c18 in posix_memalign (/usr/lib64/libasan.so.5+0xe9c18)
    #1 0x7fd6def177e6 in av_malloc (/usr/lib64/libavutil.so.56+0x277e6)

Direct leak of 2048 byte(s) in 8 object(s) allocated from:
    #0 0x7fd6e4841320 in __interceptor_realloc (/usr/lib64/libasan.so.5+0xe9320)
    #1 0x7fd6d3440a66  (/usr/lib64/xorg/modules/dri/radeonsi_dri.so+0x670a66)

Direct leak of 288 byte(s) in 10 object(s) allocated from:
    #0 0x7fd6e4841118 in calloc (/usr/lib64/libasan.so.5+0xe9118)
    #1 0x7fd6cd6a9622 in S9xGetCommandT(char const*) [clone .localalias.3] (/usr/lib64/libretro/snes9x_libretro.so+0x81622)
    #2 0x45430e in command_event_init_core /tmp/SBo/RetroArch/command.c:1364
    #3 0x45797a in command_event /tmp/SBo/RetroArch/command.c:2383
    #4 0x44500b in retroarch_main_init /tmp/SBo/RetroArch/retroarch.c:1366
    #5 0x46edfb in content_load tasks/task_content.c:281
    #6 0x471dcd in task_load_content tasks/task_content.c:889
    #7 0x47254c in command_event_cmd_exec tasks/task_content.c:1006
    #8 0x473e35 in task_push_load_content_from_playlist_from_menu tasks/task_content.c:1226
    #9 0x80d4dd in default_action_ok_load_content_from_playlist_from_menu menu/cbs/menu_cbs_ok.c:1541
    #10 0x80e904 in action_ok_playlist_entry_collection menu/cbs/menu_cbs_ok.c:1755
    #11 0x804c44 in menu_entry_action menu/widgets/menu_entry.c:455
    #12 0x8a26a4 in generic_menu_iterate menu/drivers/menu_generic.c:232
    #13 0x7bb71a in menu_driver_iterate menu/menu_driver.c:2010
    #14 0x4490f4 in runloop_check_state /tmp/SBo/RetroArch/retroarch.c:2822
    #15 0x44b349 in runloop_iterate /tmp/SBo/RetroArch/retroarch.c:3494
    #16 0x64c989 in ui_application_qt_run ui/drivers/qt/ui_qt_application.cpp:158
    #17 0x43db4f in rarch_main frontend/frontend.c:157
    #18 0x64ca7f in main ui/drivers/qt/ui_qt_application.cpp:182
    #19 0x7fd6de932c66 in __libc_start_main (/lib64/libc.so.6+0x22c66)

Direct leak of 38 byte(s) in 2 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x544012 in environ_cb_get_system_info /tmp/SBo/RetroArch/dynamic.c:231
    #2 0x7fd6cd9342b7 in retro_set_environment (/usr/lib64/libretro/snes9x_libretro.so+0x30c2b7)
    #3 0x544888 in libretro_get_system_info_lib /tmp/SBo/RetroArch/dynamic.c:391
    #4 0x544a32 in libretro_get_system_info /tmp/SBo/RetroArch/dynamic.c:429
    #5 0x455f9a in command_event /tmp/SBo/RetroArch/command.c:1885
    #6 0x7bbb7e in menu_update_libretro_info menu/menu_driver.c:2063
    #7 0x7bbb9c in menu_driver_init_internal menu/menu_driver.c:2069
    #8 0x7bbdbd in menu_driver_init menu/menu_driver.c:2105
    #9 0x5118a9 in drivers_init /tmp/SBo/RetroArch/driver.c:386
    #10 0x44506e in retroarch_main_init /tmp/SBo/RetroArch/retroarch.c:1390
    #11 0x46edfb in content_load tasks/task_content.c:281
    #12 0x471dcd in task_load_content tasks/task_content.c:889
    #13 0x47254c in command_event_cmd_exec tasks/task_content.c:1006
    #14 0x473e35 in task_push_load_content_from_playlist_from_menu tasks/task_content.c:1226
    #15 0x80d4dd in default_action_ok_load_content_from_playlist_from_menu menu/cbs/menu_cbs_ok.c:1541
    #16 0x80e904 in action_ok_playlist_entry_collection menu/cbs/menu_cbs_ok.c:1755
    #17 0x804c44 in menu_entry_action menu/widgets/menu_entry.c:455
    #18 0x8a26a4 in generic_menu_iterate menu/drivers/menu_generic.c:232
    #19 0x7bb71a in menu_driver_iterate menu/menu_driver.c:2010
    #20 0x4490f4 in runloop_check_state /tmp/SBo/RetroArch/retroarch.c:2822
    #21 0x44b349 in runloop_iterate /tmp/SBo/RetroArch/retroarch.c:3494
    #22 0x64c989 in ui_application_qt_run ui/drivers/qt/ui_qt_application.cpp:158
    #23 0x43db4f in rarch_main frontend/frontend.c:157
    #24 0x64ca7f in main ui/drivers/qt/ui_qt_application.cpp:182
    #25 0x7fd6de932c66 in __libc_start_main (/lib64/libc.so.6+0x22c66)

Direct leak of 16 byte(s) in 1 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x543c1b in environ_cb_get_system_info /tmp/SBo/RetroArch/dynamic.c:220
    #2 0x7fd6cd9342b7 in retro_set_environment (/usr/lib64/libretro/snes9x_libretro.so+0x30c2b7)
    #3 0x544888 in libretro_get_system_info_lib /tmp/SBo/RetroArch/dynamic.c:391
    #4 0x544a32 in libretro_get_system_info /tmp/SBo/RetroArch/dynamic.c:429
    #5 0x455f9a in command_event /tmp/SBo/RetroArch/command.c:1885
    #6 0x7bbb7e in menu_update_libretro_info menu/menu_driver.c:2063
    #7 0x7bbb9c in menu_driver_init_internal menu/menu_driver.c:2069
    #8 0x7bbdbd in menu_driver_init menu/menu_driver.c:2105
    #9 0x5118a9 in drivers_init /tmp/SBo/RetroArch/driver.c:386
    #10 0x44506e in retroarch_main_init /tmp/SBo/RetroArch/retroarch.c:1390
    #11 0x46edfb in content_load tasks/task_content.c:281
    #12 0x471dcd in task_load_content tasks/task_content.c:889
    #13 0x47254c in command_event_cmd_exec tasks/task_content.c:1006
    #14 0x473e35 in task_push_load_content_from_playlist_from_menu tasks/task_content.c:1226
    #15 0x80d4dd in default_action_ok_load_content_from_playlist_from_menu menu/cbs/menu_cbs_ok.c:1541
    #16 0x80e904 in action_ok_playlist_entry_collection menu/cbs/menu_cbs_ok.c:1755
    #17 0x804c44 in menu_entry_action menu/widgets/menu_entry.c:455
    #18 0x8a26a4 in generic_menu_iterate menu/drivers/menu_generic.c:232
    #19 0x7bb71a in menu_driver_iterate menu/menu_driver.c:2010
    #20 0x4490f4 in runloop_check_state /tmp/SBo/RetroArch/retroarch.c:2822
    #21 0x44b349 in runloop_iterate /tmp/SBo/RetroArch/retroarch.c:3494
    #22 0x64c989 in ui_application_qt_run ui/drivers/qt/ui_qt_application.cpp:158
    #23 0x43db4f in rarch_main frontend/frontend.c:157
    #24 0x64ca7f in main ui/drivers/qt/ui_qt_application.cpp:182
    #25 0x7fd6de932c66 in __libc_start_main (/lib64/libc.so.6+0x22c66)

Direct leak of 16 byte(s) in 1 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x543ca1 in environ_cb_get_system_info /tmp/SBo/RetroArch/dynamic.c:221
    #2 0x7fd6cd9342b7 in retro_set_environment (/usr/lib64/libretro/snes9x_libretro.so+0x30c2b7)
    #3 0x544888 in libretro_get_system_info_lib /tmp/SBo/RetroArch/dynamic.c:391
    #4 0x544a32 in libretro_get_system_info /tmp/SBo/RetroArch/dynamic.c:429
    #5 0x455f9a in command_event /tmp/SBo/RetroArch/command.c:1885
    #6 0x7bbb7e in menu_update_libretro_info menu/menu_driver.c:2063
    #7 0x7bbb9c in menu_driver_init_internal menu/menu_driver.c:2069
    #8 0x7bbdbd in menu_driver_init menu/menu_driver.c:2105
    #9 0x5118a9 in drivers_init /tmp/SBo/RetroArch/driver.c:386
    #10 0x44506e in retroarch_main_init /tmp/SBo/RetroArch/retroarch.c:1390
    #11 0x46edfb in content_load tasks/task_content.c:281
    #12 0x471dcd in task_load_content tasks/task_content.c:889
    #13 0x47254c in command_event_cmd_exec tasks/task_content.c:1006
    #14 0x473e35 in task_push_load_content_from_playlist_from_menu tasks/task_content.c:1226
    #15 0x80d4dd in default_action_ok_load_content_from_playlist_from_menu menu/cbs/menu_cbs_ok.c:1541
    #16 0x80e904 in action_ok_playlist_entry_collection menu/cbs/menu_cbs_ok.c:1755
    #17 0x804c44 in menu_entry_action menu/widgets/menu_entry.c:455
    #18 0x8a26a4 in generic_menu_iterate menu/drivers/menu_generic.c:232
    #19 0x7bb71a in menu_driver_iterate menu/menu_driver.c:2010
    #20 0x4490f4 in runloop_check_state /tmp/SBo/RetroArch/retroarch.c:2822
    #21 0x44b349 in runloop_iterate /tmp/SBo/RetroArch/retroarch.c:3494
    #22 0x64c989 in ui_application_qt_run ui/drivers/qt/ui_qt_application.cpp:158
    #23 0x43db4f in rarch_main frontend/frontend.c:157
    #24 0x64ca7f in main ui/drivers/qt/ui_qt_application.cpp:182
    #25 0x7fd6de932c66 in __libc_start_main (/lib64/libc.so.6+0x22c66)

Direct leak of 14 byte(s) in 2 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x543ef6 in environ_cb_get_system_info /tmp/SBo/RetroArch/dynamic.c:230
    #2 0x7fd6cd9342b7 in retro_set_environment (/usr/lib64/libretro/snes9x_libretro.so+0x30c2b7)
    #3 0x544888 in libretro_get_system_info_lib /tmp/SBo/RetroArch/dynamic.c:391
    #4 0x544a32 in libretro_get_system_info /tmp/SBo/RetroArch/dynamic.c:429
    #5 0x455f9a in command_event /tmp/SBo/RetroArch/command.c:1885
    #6 0x7bbb7e in menu_update_libretro_info menu/menu_driver.c:2063
    #7 0x7bbb9c in menu_driver_init_internal menu/menu_driver.c:2069
    #8 0x7bbdbd in menu_driver_init menu/menu_driver.c:2105
    #9 0x5118a9 in drivers_init /tmp/SBo/RetroArch/driver.c:386
    #10 0x44506e in retroarch_main_init /tmp/SBo/RetroArch/retroarch.c:1390
    #11 0x46edfb in content_load tasks/task_content.c:281
    #12 0x471dcd in task_load_content tasks/task_content.c:889
    #13 0x47254c in command_event_cmd_exec tasks/task_content.c:1006
    #14 0x473e35 in task_push_load_content_from_playlist_from_menu tasks/task_content.c:1226
    #15 0x80d4dd in default_action_ok_load_content_from_playlist_from_menu menu/cbs/menu_cbs_ok.c:1541
    #16 0x80e904 in action_ok_playlist_entry_collection menu/cbs/menu_cbs_ok.c:1755
    #17 0x804c44 in menu_entry_action menu/widgets/menu_entry.c:455
    #18 0x8a26a4 in generic_menu_iterate menu/drivers/menu_generic.c:232
    #19 0x7bb71a in menu_driver_iterate menu/menu_driver.c:2010
    #20 0x4490f4 in runloop_check_state /tmp/SBo/RetroArch/retroarch.c:2822
    #21 0x44b349 in runloop_iterate /tmp/SBo/RetroArch/retroarch.c:3494
    #22 0x64c989 in ui_application_qt_run ui/drivers/qt/ui_qt_application.cpp:158
    #23 0x43db4f in rarch_main frontend/frontend.c:157
    #24 0x64ca7f in main ui/drivers/qt/ui_qt_application.cpp:182
    #25 0x7fd6de932c66 in __libc_start_main (/lib64/libc.so.6+0x22c66)

Indirect leak of 2048 byte(s) in 4 object(s) allocated from:
    #0 0x7fd6e4841320 in __interceptor_realloc (/usr/lib64/libasan.so.5+0xe9320)
    #1 0x7fd6e1595ad9  (/lib64/libudev.so.1+0x5ad9)

Indirect leak of 1792 byte(s) in 4 object(s) allocated from:
    #0 0x7fd6e4841118 in calloc (/usr/lib64/libasan.so.5+0xe9118)
    #1 0x7fd6e15967e0  (/lib64/libudev.so.1+0x67e0)

Indirect leak of 1568 byte(s) in 2 object(s) allocated from:
    #0 0x7fd6e4841c18 in posix_memalign (/usr/lib64/libasan.so.5+0xe9c18)
    #1 0x7fd6def177e6 in av_malloc (/usr/lib64/libavutil.so.56+0x277e6)

Indirect leak of 768 byte(s) in 16 object(s) allocated from:
    #0 0x7fd6e4841118 in calloc (/usr/lib64/libasan.so.5+0xe9118)
    #1 0x7fd6e1595a31  (/lib64/libudev.so.1+0x5a31)

Indirect leak of 534 byte(s) in 16 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x7fd6e1595a62  (/lib64/libudev.so.1+0x5a62)

Indirect leak of 460 byte(s) in 4 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x7fd6e1598140  (/lib64/libudev.so.1+0x8140)
    #2 0x6963702f73656368  (<unknown module>)

Indirect leak of 112 byte(s) in 16 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x7fd6e1595a45  (/lib64/libudev.so.1+0x5a45)

Indirect leak of 68 byte(s) in 4 object(s) allocated from:
    #0 0x7fd6e4840f30 in malloc (/usr/lib64/libasan.so.5+0xe8f30)
    #1 0x7fd6de997b87 in vasprintf (/lib64/libc.so.6+0x87b87)

Indirect leak of 24 byte(s) in 4 object(s) allocated from:
    #0 0x7fd6e4792840 in strdup (/usr/lib64/libasan.so.5+0x3a840)
    #1 0x7fd6e1598187  (/lib64/libudev.so.1+0x8187)
    #2 0x6963702f73656368  (<unknown module>)

Indirect leak of 7 byte(s) in 1 object(s) allocated from:
    #0 0x7fd6e4841320 in __interceptor_realloc (/usr/lib64/libasan.so.5+0xe9320)
    #1 0x7fd6def17a92 in av_strdup (/usr/lib64/libavutil.so.56+0x27a92)

SUMMARY: AddressSanitizer: 11913 byte(s) leaked in 97 allocation(s).

[andres-asm]

While HW encoding does help a lot with performance, the biggest problem is elsewhere. This is recording with libx264:

FPS reader is way off, it's roughly ~15fps But there is a lot of headroom. I can tell because fast forwarding does this:

Same thing with h264_nvenc, except that the FPS counter doesn't go haywire but the builtin FPS stays pegged at 60 no matter what:

With FF:

[andres-asm]

Another example everything within a single RA session:

Not recording for reference:

Settings:

• hard sync off
• vsync on
• no rewind

Record libx264 reads 60, but it's roughly 15fps

During same recording but fast forwarding

It's actually forwarding to that speed during recording

[andres-asm]

Now for the fun part, I go to settings, video, and turn threaded video on, then back off a couple times (the number of times is not deterministic but I always end up in off for this test)

Recording libx264 shows the proper speed now

But fast forward no longer forwards much

So that's the main problem, happens regardless of the codec, it's not due to hardware encoding or the lack of that, it's something threaded related or something like that

---

Extra test:

So now within the same launch I go and change this:

Recording with the same settings but nvenc is full speed as expected:

And I can even FF and it's all correct:

[andres-asm]

The issue is not existent with GPU recording off so it must be related to the way readbacks are performed

libx264

nvenc

Still though, even for non-gpu recording there is quite a perf gap when using HW encoding as expected.

[Sanaki]

Well, I was going to open an issue about this, but it seems you've already covered it and then some. Still, I can confirm pretty much everything you've said here. Interestingly, threaded video doesn't need to be left on. If you toggle it on and back off, the game will run at full speed while recording. Stopping and restarting recording will also continue to be full speed, but the reinit from toggling threaded video has to be done during recording for it to work.

[thingsiplay]

I am currently experiencing the same issue here on PC/Linux. After starting recording I have to go into menu and toggle video_threading to get smooth gameplay while recording. Interestingly without this workaround the gameplay is choppy and slow at high resolution, but the captured video on the disk is perfectly fine. This really affects only gameplay.