[MSE][GStreamer] take playbin's states lock when sending seek event

[emutavchi]

This fixes possible race between application (triggering another seek from 'seeked' event) and 'state change' continuation (triggered by playbin).

Top level bin element does change the state as result of 'async-done' handling from previous seek request(see gst_bin_continue_func in gstbin.c). Which may race with handling of 'async-start' posted by sinks on flushing seek. And may leave the pipeline in inconsistent state and 'hanging' seek that never finishes.

By taking the states lock of top level bin element player will wait for possible state change continuation to complete before sending next seek event.

[emutavchi]

Here is a test page where issue can be reproduced: https://github.com/emutavchi/tests/blob/master/mse/mse_seq_seek_test.html. Occasionally seek sequence will stall with video in 'seeking' state. The expected behavior is to fast forward and rewind by 100 ms, then playback till the end.

[philn]

This fixes possible race between application (triggering another seek from 'seeked' event) and 'state change' continuation (triggered by playbin).

Could we have mutex for this instead?

Locking the whole pipeline state doesn't seem like a good idea, especially for a flushing seek on a not-yet-prerolled pipeline.

[emutavchi]

@philn

Could we have mutex for this instead?

I don't think introducing new lock in webkit media player will work in this case. We need to sync gstbin (gst_bin_continue_func) and webkit media player seek. It is either bin element state lock, object lock or custom patch to introduce new lock in for this case in gstbin element specifically. The state lock option looks safe to me, see below

Locking the whole pipeline state doesn't seem like a good idea, especially for a flushing seek on a not-yet-prerolled pipeline

This is what gst_element_send_event does by default. I mean webkit media player calls gst_element_seek(source, ...), that calls gst_element_send_event(seek_event), that grabs the state lock before calling 'send_event' class method. The problem is that new version of MSE player sends seek event directly to the source, and so top level bin state lock is not taken.

Edit: typo

[philn]

I stand aside and defer to our MSE reviewers.

[calvaris]

I am trying to reproduce what you mention, in the RPi I can't see any blocks, what I do see is that sometimes the pipeline can't go back to the beginning to then stop seeking and finish the playback because when seeking backwards, it plays a bit again and it is almost impossible to go back. Sometimes it even goes forward a bit causing the playback to end because the whole use case is executed. I'll try with the reference box just in case there's different behavior.

[calvaris]

From my tests on the reference box, what I see is that it is even harder for it to reach the beginning of the playback when seeking backwards and it always ends up at the end with the seeking blocked (with and without your patch), but I don't know if this is the behavior you're experiencing.

[emutavchi]

Hi @calvaris ,

I am trying to reproduce what you mention, in the RPi I can't see any blocks

I haven't tried RPI. It is quite easy reproducible on Realtek and Amlogic devices we have.

but I don't know if this is the behavior you're experiencing.

The expected behavior is that it seeks forward almost till the end (duration of buffered - duration of 1 segment), then rewinds to the beginning (stops when it reaches 1 second) and then resumes the playback. The test succeeds if all seeks succeeded and video played till then end and after that video was "cleanup" on "ended" event. I probably should have put some message in the test to indicate the success.

when seeking backwards and it always ends up at the end with the seeking blocked

This sounds similar the behavior I observed before the change. Browser wasn't really blocked (hanging), just video tag was stuck in "seeking" state with gstreamer pipeline stuck in "PLAYING" state with one(or both) of the sinks in "PAUSED". For some reason it wouldn't commit to "PAUSED" and send async-done event after prerolling. Locking playbin states solved the problem for us.

[calvaris]

I just tried with and without your patch in the reference box with the same result. With that I can't test and assess if I merge this or propose an alternative.

The behavior I am getting is what I mentioned above. It seeks forward and when it begins to seek backwards, given the small amount of seek + playback it still manages to move forward and ends playback without going to the beginning, and ends up blocked. With and without your patch.

[emutavchi]

@calvaris you might need this change as well https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1338. I can try reproducing with extra gst logging. let me know if that would be helpful

[calvaris]

You need to enable `GST_DEBUG="webkit*:7" and apply the following patch.

debug.patch.gz

Also using this tuned file:

mse_seq_seek_test.html.gz

@emutavchi

But anyway, IMHO, we should fix #1338 first if we have a dependency because then we could be relying on something that might not be merged for whatever reason.

[emutavchi]

@calvaris here is reproduction from Realtek device.

Reproduced on wpe-2.38 at b907bcc23140077c1193a7cf30166e96036fa053 with additional change for https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1338.

Attached log is for reproduction on wpe-2.38 from fc1703ed69006e92c6d014d1de7d1ea7b9d2f915 with extra patches from meta-rdk-ext (https://code.rdkcentral.com/r/plugins/gitiles/rdk/components/generic/rdk-oe/meta-rdk-ext/+/refs/heads/rdk-next/recipes-extended/wpe-webkit/wpe-webkit_2.38.4.bb). I'll attach fresh logs from latest wpe-2.38 later today

The test got stuck in seeking state, after seek to 5.333000. Sinks were in playing state, so playback continued but without any observable state change from test.

I've captured logs with GST_DEBUG='webkit*:7,GST_STATES:7,bin:5,2'

console.log.rtk.gz

[emutavchi]

Here is log for reproduction with wpe-2.38 from b907bcc23140077c1193a7cf30166e96036fa053 + https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1338: console_b907bcc23140077c1193a7cf30166e96036fa053.log.rkt.gz

for reference I'm attaching logs for case when test succeeds, wpe-2.38 + https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1338 + https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1339: console.log.good.rtk.gz

[emutavchi]

Logs for reproduction on wpe-2.38 + https://github.com/WebPlatformForEmbedded/WPEWebKit/pull/1338 + debug.patch: console+b907bcc23140077c1193a7cf30166e96036fa053+gst-debug+debug_patch.log.rtk.gz

[calvaris]

Landed https://bugs.webkit.org/show_bug.cgi?id=275566 upstream. Backported to 2.42 as aedbebdec216 and to 2.38 as 2b4f979900d1.