search

Frogging-Family / wine-tkg-git

The wine-tkg build systems, to create custom Wine and Proton builds
859 stars 155 forks source link

[valve-exp-bleeding] Broken gstreamer playback #1219

Closed adolfintel closed 1 month ago

adolfintel commented 1 month ago

I noticed that games are having issues with video playback on newer builds of valve-exp-bleeding. I'm trying to bisect the exact commit that broke it, but it happened somewhere between June 24 and July 6, I'll update the issue when I find it.

Here's the log from gstreamer, it fails both with and without vaapi.

0:00:00.140566985  5785 0x75109c011560 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "bin"
0:00:00.140590765  5785 0x75109c011560 LOG                     WINE wg_allocator.c:157:wg_allocator_init: allocator 0x75109c450ea0
0:00:00.140598975  5785 0x75109c011560 TRACE                   WINE wg_media_type.c:404:caps_from_video_format: subtype {34363248-0000-0010-8000-00aa00389b71} 0x0, FPS 0:0, aperture (0,0)-(0,0), PAR 0:0, videoFlags 0.
0:00:00.140602445  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: ---------------------------------------------------------------------------
0:00:00.140605135  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: extra bytes:
0:00:00.140608885  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: 00000000: 00 00 00 01 67 4d 40 34 95 90 03 c0 04 3e c0 44  ....gM@4.....>.D
0:00:00.140612165  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: 00000010: 00 00 0f a0 00 07 53 02 10 00 00 00 01 68 eb 8f  ......S......h..
0:00:00.140614605  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: 00000020: 20                                                               
0:00:00.140616645  5785 0x75109c011560 MEMDUMP                 WINE wg_media_type.c:409:caps_from_video_format: ---------------------------------------------------------------------------
0:00:00.140634805  5785 0x75109c011560 TRACE                   WINE wg_media_type.c:454:caps_from_media_type: caps video/x-h264, codec_data=(buffer)00000001674d4034959003c0043ec04400000fa000075302100000000168eb8f20, stream-format=(string)byte-stream, alignment=(string)au
0:00:00.140639805  5785 0x75109c011560 INFO                    WINE wg_transform.c:553:wg_transform_create: transform 0x75109c450420 input caps video/x-h264, codec_data=(buffer)00000001674d4034959003c0043ec04400000fa000075302100000000168eb8f20, stream-format=(string)byte-stream, alignment=(string)au
0:00:00.140645455  5785 0x75109c011560 TRACE                   WINE wg_media_type.c:404:caps_from_video_format: subtype {3231564e-0000-0010-8000-00aa00389b71} 1920x1080, FPS 30000:1001, aperture (0,0)-(1920,1080), PAR 1:1, videoFlags 0.
0:00:00.140654825  5785 0x75109c011560 TRACE                   WINE wg_media_type.c:454:caps_from_media_type: caps video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30000/1001
0:00:00.140658635  5785 0x75109c011560 INFO                    WINE wg_transform.c:558:wg_transform_create: transform 0x75109c450420 output caps video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1080, pixel-aspect-ratio=(fraction)1/1, framerate=(fraction)30000/1001
0:00:00.140661415  5785 0x75109c011560 LOG                     WINE unix_private.h:133:touch_h264_used_tag: h264 is used
0:00:00.140663525  5785 0x75109c011560 WARN                    WINE unix_private.h:155:touch_h264_used_tag: STEAM_COMPAT_SHADER_PATH not set, cannot create h264-used file
0:00:00.141097235  5785 0x75109c011560 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "h264parse"
0:00:00.141106796  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseParse@0x75109c452b50> adding pad 'sink'
0:00:00.141111416  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseParse@0x75109c452b50> adding pad 'src'
0:00:00.141117106  5785 0x75109c011560 INFO               baseparse gstbaseparse.c:4067:gst_base_parse_set_pts_interpolation:<GstH264Parse@0x75109c452b50> PTS interpolation: no
0:00:00.141119576  5785 0x75109c011560 INFO               baseparse gstbaseparse.c:4085:gst_base_parse_set_infer_ts:<GstH264Parse@0x75109c452b50> TS inferring: no
0:00:00.141124496  5785 0x75109c011560 INFO                    WINE unixlib.c:88:factory_create_element: Created element <h264parse1> from factory <h264parse>.
0:00:00.141136096  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<h264parse1> completed state change to NULL
0:00:00.141139056  5785 0x75109c011560 DEBUG                   WINE unixlib.c:182:append_element: Linked h264parse1 element 0x75109c452b50.
0:00:00.141433556  5785 0x75109c011560 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "avdec_h264"
0:00:00.141446256  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstVideoDecoder@0x75109c456250> adding pad 'sink'
0:00:00.141450086  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstVideoDecoder@0x75109c456250> adding pad 'src'
0:00:00.141456956  5785 0x75109c011560 INFO                    WINE unixlib.c:88:factory_create_element: Created element <avdec_h264-1> from factory <avdec_h264>.
0:00:00.141462416  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<avdec_h264-1> completed state change to NULL
0:00:00.141466106  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstutils.c:1818:gst_element_link_pads_full: trying to link element h264parse1:(any) to element avdec_h264-1:(any)
0:00:00.141470586  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1080:gst_pad_check_link: trying to link h264parse1:src and avdec_h264-1:sink
0:00:00.141478596  5785 0x75109c011560 INFO                GST_PADS gstpad.c:4398:gst_pad_peer_query:<avdec_h264-1:src> pad has no peer
0:00:00.141492236  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1634:prepare_link_maybe_ghosting: h264parse1 and avdec_h264-1 in same bin, no need for ghost pads
0:00:00.141497766  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2440:gst_pad_link_prepare: trying to link h264parse1:src and avdec_h264-1:sink
0:00:00.141501496  5785 0x75109c011560 INFO                GST_PADS gstpad.c:4398:gst_pad_peer_query:<avdec_h264-1:src> pad has no peer
0:00:00.141508966  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2621:gst_pad_link_full: linked h264parse1:src and avdec_h264-1:sink, successful
0:00:00.141511306  5785 0x75109c011560 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.141514446  5785 0x75109c011560 INFO               GST_EVENT gstpad.c:6017:gst_pad_send_event_unchecked:<h264parse1:src> Received event on flushing pad. Discarding
0:00:00.141518866  5785 0x75109c011560 DEBUG                   WINE unixlib.c:182:append_element: Linked avdec_h264-1 element 0x75109c456250.
0:00:00.141522436  5785 0x75109c011560 DEBUG                   WINE unixlib.c:388:set_max_threads: avdec_h264 found, setting max-threads to 16.
0:00:00.141526716  5785 0x75109c011560 INFO     GST_ELEMENT_FACTORY gstelementfactory.c:489:gst_element_factory_create_with_properties: creating element "videoconvert"
0:00:00.141532816  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x75109c459d90> adding pad 'sink'
0:00:00.141537046  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:758:gst_element_add_pad:<GstBaseTransform@0x75109c459d90> adding pad 'src'
0:00:00.141545576  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<videoconvert1> completed state change to NULL
0:00:00.141548556  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstutils.c:1818:gst_element_link_pads_full: trying to link element avdec_h264-1:(any) to element videoconvert1:(any)
0:00:00.141551616  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1080:gst_pad_check_link: trying to link avdec_h264-1:src and videoconvert1:sink
0:00:00.141555836  5785 0x75109c011560 INFO                GST_PADS gstpad.c:4398:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:00.141877366  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1634:prepare_link_maybe_ghosting: avdec_h264-1 and videoconvert1 in same bin, no need for ghost pads
0:00:00.141882536  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2440:gst_pad_link_prepare: trying to link avdec_h264-1:src and videoconvert1:sink
0:00:00.141886406  5785 0x75109c011560 INFO                GST_PADS gstpad.c:4398:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:00.142186096  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2621:gst_pad_link_full: linked avdec_h264-1:src and videoconvert1:sink, successful
0:00:00.142188406  5785 0x75109c011560 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.142191176  5785 0x75109c011560 INFO               GST_EVENT gstpad.c:6017:gst_pad_send_event_unchecked:<avdec_h264-1:src> Received event on flushing pad. Discarding
0:00:00.142196116  5785 0x75109c011560 DEBUG                   WINE unixlib.c:182:append_element: Linked videoconvert1 element 0x75109c459d90.
0:00:00.142202306  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1080:gst_pad_check_link: trying to link '':src and h264parse1:sink
0:00:00.142204816  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1104:gst_pad_check_link: Src pad '':src has no parent, failed
0:00:00.142210466  5785 0x75109c011560 TRACE                   WINE wg_transform.c:296:transform_src_query_cb: transform 0x75109c450420, ignoring caps query: 0x75109c457e70, GstQueryCaps, filter=(GstCaps)"NULL", caps=(GstCaps)"NULL";
0:00:00.142217066  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad h264parse1:sink
0:00:00.142220966  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2440:gst_pad_link_prepare: trying to link '':src and h264parse1:sink
0:00:00.142224446  5785 0x75109c011560 TRACE                   WINE wg_transform.c:296:transform_src_query_cb: transform 0x75109c450420, ignoring caps query: 0x75109c457e70, GstQueryCaps, filter=(GstCaps)"NULL", caps=(GstCaps)"NULL";
0:00:00.142228986  5785 0x75109c011560 INFO                GST_PADS gstpad.c:4398:gst_pad_peer_query:<videoconvert1:src> pad has no peer
0:00:00.142853977  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2621:gst_pad_link_full: linked '':src and h264parse1:sink, successful
0:00:00.142858437  5785 0x75109c011560 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.142861537  5785 0x75109c011560 INFO               GST_EVENT gstpad.c:6017:gst_pad_send_event_unchecked:<'':src> Received event on flushing pad. Discarding
0:00:00.142865337  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1080:gst_pad_check_link: trying to link videoconvert1:src and '':sink
0:00:00.142867867  5785 0x75109c011560 INFO                GST_PADS gstutils.c:1109:gst_pad_check_link: Sink pad videoconvert1:src has no parent, failed
0:00:00.142872227  5785 0x75109c011560 LOG                     WINE wg_transform.c:387:transform_sink_query_caps: transform 0x75109c450420, caps query: 0x75109c458b50, GstQueryCaps, filter=(GstCaps)"NULL", caps=(GstCaps)"NULL";
0:00:00.142877637  5785 0x75109c011560 INFO                    WINE wg_transform.c:403:transform_sink_query_caps: Returning caps video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1080
0:00:00.142886257  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:1016:gst_element_get_static_pad: found pad videoconvert1:src
0:00:00.142890967  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2440:gst_pad_link_prepare: trying to link videoconvert1:src and '':sink
0:00:00.143357917  5785 0x75109c011560 LOG                     WINE wg_transform.c:387:transform_sink_query_caps: transform 0x75109c450420, caps query: 0x75109c458b50, GstQueryCaps, filter=(GstCaps)"NULL", caps=(GstCaps)"NULL";
0:00:00.143363167  5785 0x75109c011560 INFO                    WINE wg_transform.c:403:transform_sink_query_caps: Returning caps video/x-raw, format=(string)NV12, width=(int)1920, height=(int)1080
0:00:00.143373667  5785 0x75109c011560 INFO                GST_PADS gstpad.c:2621:gst_pad_link_full: linked videoconvert1:src and '':sink, successful
0:00:00.143375667  5785 0x75109c011560 INFO               GST_EVENT gstevent.c:1687:gst_event_new_reconfigure: creating reconfigure event
0:00:00.143378097  5785 0x75109c011560 INFO               GST_EVENT gstpad.c:6017:gst_pad_send_event_unchecked:<videoconvert1:src> Received event on flushing pad. Discarding
0:00:00.143388667  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<videoconvert1> current NULL pending VOID_PENDING, desired next READY
0:00:00.143391737  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<videoconvert1> completed state change to READY
0:00:00.143394377  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.143398877  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'videoconvert1' changed state to 2(READY) successfully
0:00:00.143402047  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<avdec_h264-1> current NULL pending VOID_PENDING, desired next READY
0:00:00.143404597  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<avdec_h264-1> completed state change to READY
0:00:00.143407277  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<avdec_h264-1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.143410487  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'avdec_h264-1' changed state to 2(READY) successfully
0:00:00.143413207  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<h264parse1> current NULL pending VOID_PENDING, desired next READY
0:00:00.143415557  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<h264parse1> completed state change to READY
0:00:00.143417827  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<h264parse1> notifying about state-changed NULL to READY (VOID_PENDING pending)
0:00:00.143421067  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'h264parse1' changed state to 2(READY) successfully
0:00:00.143424797  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2796:gst_element_continue_state:<wg_transform> committing state from NULL to READY, pending PAUSED, next PAUSED
0:00:00.143432117  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<wg_transform> notifying about state-changed NULL to READY (PAUSED pending)
0:00:00.143436077  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2804:gst_element_continue_state:<wg_transform> continue state change READY to PAUSED, final PAUSED
0:00:00.143440617  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<videoconvert1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.143445227  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<videoconvert1> completed state change to PAUSED
0:00:00.143447637  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.143450957  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'videoconvert1' changed state to 3(PAUSED) successfully
0:00:00.143453877  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<avdec_h264-1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.143459627  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<avdec_h264-1> completed state change to PAUSED
0:00:00.143461987  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<avdec_h264-1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.143465207  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'avdec_h264-1' changed state to 3(PAUSED) successfully
0:00:00.143467927  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<h264parse1> current READY pending VOID_PENDING, desired next PAUSED
0:00:00.143480667  5785 0x75109c011560 TRACE                   WINE wg_transform.c:296:transform_src_query_cb: transform 0x75109c450420, ignoring scheduling query: 0x75109c5afe60, GstQueryScheduling, flags=(GstSchedulingFlags)0, minsize=(int)1, maxsize=(int)-1, align=(int)0;
0:00:00.143518127  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<h264parse1> completed state change to PAUSED
0:00:00.143521047  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<h264parse1> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.143524617  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'h264parse1' changed state to 3(PAUSED) successfully
0:00:00.143527797  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<wg_transform> completed state change to PAUSED
0:00:00.143530107  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<wg_transform> notifying about state-changed READY to PAUSED (VOID_PENDING pending)
0:00:00.143533067  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2070:gst_bin_get_state_func:<wg_transform> getting state
0:00:00.143543047  5785 0x75109c011560 TRACE                   WINE wg_transform.c:457:transform_sink_event_cb: transform 0x75109c450420, ignoring stream-start event: 0x75109c45ce50, time 99:99:99.999999999, seq-num 56, GstEventStreamStart, stream-id=(string)stream, flags=(GstStreamFlags)GST_STREAM_FLAG_NONE;
0:00:00.143550247  5785 0x75109c011560 INFO               GST_EVENT gstevent.c:918:gst_event_new_caps: creating caps event video/x-h264, codec_data=(buffer)00000001674d4034959003c0043ec04400000fa000075302100000000168eb8f20, stream-format=(string)byte-stream, alignment=(string)au
0:00:00.143557737  5785 0x75109c011560 WARN               h264parse gsth264parse.c:3707:gst_h264_parse_set_caps:<h264parse1> H.264 bytestream caps with codec_data is not expected, send SPS/PPS in-band with data or in streamheader field
0:00:00.143562297  5785 0x75109c011560 WARN               h264parse gsth264parse.c:3718:gst_h264_parse_set_caps:<h264parse1> refused caps video/x-h264, codec_data=(buffer)00000001674d4034959003c0043ec04400000fa000075302100000000168eb8f20, stream-format=(string)byte-stream, alignment=(string)au
0:00:00.143567117  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2145:gst_pad_unlink: unlinking videoconvert1:src(0x75109c458010) and '':sink(0x75109c452470)
0:00:00.143571067  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2200:gst_pad_unlink: unlinked videoconvert1:src and '':sink
0:00:00.143577057  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2145:gst_pad_unlink: unlinking '':src(0x75109c452180) and h264parse1:sink(0x75109c453960)
0:00:00.143579737  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2200:gst_pad_unlink: unlinked '':src and h264parse1:sink
0:00:00.143583947  5785 0x75109c011560 LOG                     WINE wg_allocator.c:264:wg_allocator_destroy: allocator 0x75109c450ea0
0:00:00.143586537  5785 0x75109c011560 LOG                     WINE wg_allocator.c:175:wg_allocator_finalize: allocator 0x75109c450ea0
0:00:00.143588757  5785 0x75109c011560 INFO                    WINE wg_allocator.c:273:wg_allocator_destroy: Destroyed buffer allocator 0x75109c450ea0
0:00:00.143594277  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<videoconvert1> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.143599107  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<videoconvert1> completed state change to READY
0:00:00.143601527  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.143605057  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'videoconvert1' changed state to 2(READY) successfully
0:00:00.143607827  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<avdec_h264-1> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.143613577  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<avdec_h264-1> completed state change to READY
0:00:00.143615847  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<avdec_h264-1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.143618957  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'avdec_h264-1' changed state to 2(READY) successfully
0:00:00.143621567  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<h264parse1> current PAUSED pending VOID_PENDING, desired next READY
0:00:00.143631497  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<h264parse1> completed state change to READY
0:00:00.143633937  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<h264parse1> notifying about state-changed PAUSED to READY (VOID_PENDING pending)
0:00:00.143637187  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'h264parse1' changed state to 2(READY) successfully
0:00:00.143640537  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2796:gst_element_continue_state:<wg_transform> committing state from PAUSED to READY, pending NULL, next NULL
0:00:00.143642887  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<wg_transform> notifying about state-changed PAUSED to READY (NULL pending)
0:00:00.143645727  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2804:gst_element_continue_state:<wg_transform> continue state change READY to NULL, final NULL
0:00:00.143649567  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<videoconvert1> current READY pending VOID_PENDING, desired next NULL
0:00:00.143652527  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<videoconvert1> completed state change to NULL
0:00:00.143654947  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<videoconvert1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.143658137  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'videoconvert1' changed state to 1(NULL) successfully
0:00:00.143660947  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<avdec_h264-1> current READY pending VOID_PENDING, desired next NULL
0:00:00.143663877  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<avdec_h264-1> completed state change to NULL
0:00:00.143666077  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<avdec_h264-1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.143669217  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'avdec_h264-1' changed state to 1(NULL) successfully
0:00:00.143671717  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2480:gst_bin_element_set_state:<h264parse1> current READY pending VOID_PENDING, desired next NULL
0:00:00.143674517  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<h264parse1> completed state change to NULL
0:00:00.143676697  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<h264parse1> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.143679777  5785 0x75109c011560 INFO              GST_STATES gstbin.c:2939:gst_bin_change_state_func:<wg_transform> child 'h264parse1' changed state to 1(NULL) successfully
0:00:00.143682457  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2824:gst_element_continue_state:<wg_transform> completed state change to NULL
0:00:00.143684697  5785 0x75109c011560 INFO              GST_STATES gstelement.c:2724:_priv_gst_element_state_changed:<wg_transform> notifying about state-changed READY to NULL (VOID_PENDING pending)
0:00:00.143689597  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2145:gst_pad_unlink: unlinking avdec_h264-1:src(0x75109c456910) and videoconvert1:sink(0x75109c4585e0)
0:00:00.143692887  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2200:gst_pad_unlink: unlinked avdec_h264-1:src and videoconvert1:sink
0:00:00.143696137  5785 0x75109c011560 INFO           GST_PARENTAGE gstbin.c:1805:gst_bin_remove_func:<wg_transform> removed child "videoconvert1"
0:00:00.143700837  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3400:gst_element_dispose:<videoconvert1> 0x75109c459d90 dispose
0:00:00.143703117  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<videoconvert1> removing pad 'sink'
0:00:00.143706517  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<videoconvert1> removing pad 'src'
0:00:00.143709297  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3446:gst_element_dispose:<videoconvert1> 0x75109c459d90 parent class dispose
0:00:00.143711977  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3478:gst_element_finalize:<videoconvert1> 0x75109c459d90 finalize
0:00:00.143713997  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3483:gst_element_finalize:<videoconvert1> 0x75109c459d90 finalize parent
0:00:00.143717187  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2145:gst_pad_unlink: unlinking h264parse1:src(0x75109c453bb0) and avdec_h264-1:sink(0x75109c4566c0)
0:00:00.143720287  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstpad.c:2200:gst_pad_unlink: unlinked h264parse1:src and avdec_h264-1:sink
0:00:00.143723277  5785 0x75109c011560 INFO           GST_PARENTAGE gstbin.c:1805:gst_bin_remove_func:<wg_transform> removed child "avdec_h264-1"
0:00:00.143726017  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3400:gst_element_dispose:<avdec_h264-1> 0x75109c456250 dispose
0:00:00.143728017  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<avdec_h264-1> removing pad 'sink'
0:00:00.143730497  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<avdec_h264-1> removing pad 'src'
0:00:00.143733257  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3446:gst_element_dispose:<avdec_h264-1> 0x75109c456250 parent class dispose
0:00:00.143736687  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3478:gst_element_finalize:<avdec_h264-1> 0x75109c456250 finalize
0:00:00.143738597  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3483:gst_element_finalize:<avdec_h264-1> 0x75109c456250 finalize parent
0:00:00.143741897  5785 0x75109c011560 INFO           GST_PARENTAGE gstbin.c:1805:gst_bin_remove_func:<wg_transform> removed child "h264parse1"
0:00:00.143744547  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3400:gst_element_dispose:<h264parse1> 0x75109c452b50 dispose
0:00:00.143746487  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<h264parse1> removing pad 'sink'
0:00:00.143748917  5785 0x75109c011560 INFO        GST_ELEMENT_PADS gstelement.c:875:gst_element_remove_pad:<h264parse1> removing pad 'src'
0:00:00.143751587  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3446:gst_element_dispose:<h264parse1> 0x75109c452b50 parent class dispose
0:00:00.143755697  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3478:gst_element_finalize:<h264parse1> 0x75109c452b50 finalize
0:00:00.143757677  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3483:gst_element_finalize:<h264parse1> 0x75109c452b50 finalize parent
0:00:00.143759797  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3400:gst_element_dispose:<wg_transform> 0x75109c4508e0 dispose
0:00:00.143761737  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3446:gst_element_dispose:<wg_transform> 0x75109c4508e0 parent class dispose
0:00:00.143763697  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3478:gst_element_finalize:<wg_transform> 0x75109c4508e0 finalize
0:00:00.143765657  5785 0x75109c011560 INFO         GST_REFCOUNTING gstelement.c:3483:gst_element_finalize:<wg_transform> 0x75109c4508e0 finalize parent
0:00:00.143767757  5785 0x75109c011560 ERROR                   WINE wg_transform.c:757:wg_transform_create: Failed to create winegstreamer transform.
401.536:0110:0224:info:vkd3d-proton:dxgi_vk_swap_chain_recreate_swapchain_in_present_task: Got 3 swapchain images.
adolfintel commented 1 month ago

I wasn't able to bisect the exact commit but it's something in valve's wine between commit 8d6dcef50fc084c560f3dc6cf5ceba1ca19b9835 (good, July 4) and 727b74b4d1b1b970143800817ca42fcb594fe2d0 (bad, July 5). They seem to have implemented a new video transcoder that's active for all games (06d7664cc3e09a0483d1da2dc5a6cee00a417592) with no fallback, but almost all of the intermediate commits don't compile. Maybe it needs to be disabled for non proton builds?

mikeserv-git commented 1 month ago

Yeah, this breaks the proton media converter for me. The libprotonmediaplayer.so compiled OK (and looks correct on the system with its linkage) but doesn't work at runtime. At first I thought it was due to Steam's pinned libraries (had a symbol missing from this libcurl.so.4 symlink to an incorrect library). Well it still could be, but it's more than just what's in pinned_libs_64.

(wine:6747): GStreamer-WARNING **: 17:50:34.262: Failed to load plugin '/usr/lib/gstreamer-1.0/libgstcurl.so': /storage3/shit/steam/ubuntu12_32/steam-runtime/pinned_libs_64/libcurl.so.4: version `CURL_OPENSSL_4' not found (required by /usr/lib/gstreamer-1.0/libgstcurl.so)
0:00:00.059417618  6747 0x7fc95c0e8b80 ERROR                   WINE wg_source.c:423:check_decoding_support: pad <avdec_h264-0:sink>
0:00:00.060246240  6747 0x7fc95c0e8b80 ERROR                   WINE wg_source.c:423:check_decoding_support: pad <avdec_aac0:sink>
4507.925:0138:03ec:fixme:mfplat:topology_loader_Load iface 00000000250A3C20, input_topology 00000000250A9C70, ret_topology 000000005C9BFCF8, current_topology 0000000000000000 stub!
0:00:00.068932993  6747 0x7fc95c0e8b80 ERROR                   WINE wg_transform.c:757:wg_transform_create: Failed to create winegstreamer transform.
0:00:00.070584045  6747 0x7fc95c0e8b80 ERROR                   WINE wg_transform.c:757:wg_transform_create: Failed to create winegstreamer transform.

However, I got rid of that error by removing the pinned_libs_64/libcurl.so.4 symlink, but it still doesn't play the videos (black screen) and fails to create the contexts. I also tried dropping in my own libcurl with the same result. It's not just that.

The last time I tried a game using that media foundation was with proton_tkg_experimental.bleeding.edge.9.0.105874.20240703 that I built on July 03 and it still worked then. I'd think this is the same issue.

mikeserv-git commented 1 month ago

This is going to be a "won't fix" I see. Using a full gstreamer is not a supported use case. If this is what they are doing going forward, then are we to build in a crippled gstreamer?

I tried last night but only succeeded in not only a black screen but no audio for mp4's (was testing Borderlands 3 which cannot progress, as quest triggers are tied to completion of the embedded videos as is the case for most games that use that Unreal4/mfplat bollocks. I guess I'll have to find their gstreamer config.

My proton-tkg builds are actually the only place that protonmediaconverter has ever worked for me. Against my gstreamer (those are packages I roll). It's never worked for me on Arch with Valve's Protons, I used to have to drop in those mf-installcab libraries (which stopped working) before I discovered this. It never worked in Proton-GE for me either, even when I did my own builds (all in podman container against Valves environment... pointless build). My first proton-tkg build was the first time I ever saw that protonmediaconverter work.

Tk-Glitch commented 1 month ago

I'm experimenting with it to find some kind of compromise but yeah the switch made it both better and worse in different ways :D Quite a few things to adapt in our build system too, and not that much time and energy on my end. Things are moving forward nonetheless and I'm hopeful !

mikeserv-git commented 1 month ago

Oh jeeze... I've been screwing around with gstreamer for most of my available day here, trying to duplicate valve's build (I found the top level proton Makefile.in had a lot of configuration clues) and use it in this one etc. I just gave up and did a normal proton-tkg build to use for the rest of my games (hey, why settle for yesterday's when I can have what I was going to have today) without enabling gstreamer in the build or anything.

This clone of valve bleeding edge seems to work. Borderlands 3 is working again. I'm not dreaming (I rebooted even, to make sure all environments are cleared... somewhat superstitiously), it works on the intro screens and embedded in game.

I am at a loss to see anything that has changed recently enough to affect this today since my last build, nothing in this project that I can see, however I'm not so familiar with Valve, so I could be missing it in their git web interfaces and submodules etc.

If someone else doing a valve bleeding edge build of proton-tkg can confirm that it works again built against your system's gstreamer, that would be good. My uncertainty is that I rebuilt mine today, and I can't remember the time line. Having this working right now is an unexpected result (from my observations). I do disable some stuff vs. Arch PKGBUILD to avoid getting unwanted/unnecessary dependencies on the system, but nothing that should have affected this. I don't think it's relevant, but I'll elabourate more if it seems to be.

adolfintel commented 1 month ago

@mikeserv-git can you share the config used in your build?

mikeserv-git commented 1 month ago

If you think it will help you, sure thing. I actually haven't been doing that much to gstreamer on this Arch install, just to avoid installing some things I don't need, and build it the way I like things to be. I'll give a .diff against Arch's current gstreamer PKGBUILD as well as my PKGBUILD for context.

Also, I build a lot of my own packages and I don't like Arch's dog food (hardening flags and some very silly things like LTO that should be opt in, not opt out etc.) Not sure if it matters, but this is what I do in /etc/makepkg.conf so as to completely describe my environment here.

CFLAGS="-march=alderlake -O2 -pipe -fno-plt" CXXFLAGS="$CFLAGS" LDFLAGS="-Wl,-O1,--sort-common,--as-needed" RUSTFLAGS="-C target-cpu=alderlake -C debuginfo=0"

OPTIONS=(strip docs !libtool !staticlibs emptydirs zipman purge !debug !lto)

(just in case, I'll mention that AVX will subtly break DXVK and vkd3d-proton, so don't anyone use -march=anything that turns it on for those parts of a proton build)

What you're probably more interested in is my proton-tkg config, what I'll do is give all the files that I change. Since it's multiple files and I'm not sure how well I'll make out with the attachment posting interface, I'll put them in a .tar.gz and you can get them from my web server in the link below.

For gstreamer in case you want to look at that: gstreamerpkgbuild.diff PKGBUILD

For wine-tkg-git: proton-tkg/proton-tkg.sh proton-tkg/proton-tkg.cfg proton-tkg/proton-tkg-profiles/advanced-customization.cfg proton-tkg/proton_template/conf/usersettings.py

This is for a 1) Valve Bleeding Edge choice when running proton-tkg.sh

Note that I have -march= settings in some of those files.

http://www.mikeserv.com/files/wine-tkg-configs_mikeserv.tar.gz

It will unpack to wine-tkg-configs

adolfintel commented 1 month ago

I just retested this and I think it's been fixed. Can you confirm that it works for you as well @mikeserv-git ?

mikeserv-git commented 1 month ago

I just did a build a few nights ago and was still fine, but I just did one right now (Valve Bleeding Edge proton-tkg) just to make sure, and I'm still fine. I tested Borderlands 3 :-)

adolfintel commented 1 month ago

Closing the issue then