pause/resume gstreamer stream when video stream stops/starts #209

thiccaxe · 2023-09-05T20:48:16Z

fixes some issues from #207

fduncanh · 2024-04-21T17:47:46Z

There are changes in pause/resume in gstreamer-1.24 (to do with locks) that breaks Uxplay (commenting out these pause/resume calls fixes the brokenness). See issue #284 I give details in the final comment.

(I found the place where the regression happen by finding which merge in gstreamer 1.24 development triggered the error in uxplay) There is probably a simple fix of your code in Uxplay to repair our use of pause/resume.

Arch is the only distro that has moved to gstreamer 1.24, which is a good place for testing.

I also learned how to build , install (in the users home directory) and use specific merges (like "e506f9c2") of gstreamer
from gitlab.gstreamer.org/gstreamer/gstreamer for testing purposes without destroying or removing the distribution-supplied gstreamer.

If you need details I can write up a note.

thiccaxe · 2024-04-21T18:13:04Z

Yep, the fix was a bit of a hack. I didn't really have an understanding of gstreamer when putting it together. What I guess might be happening is that earlier, when we paused it only paused the gstreamer internal clock. But the A/V in the buffer still flowed through. Then when it was unpaused there wouldn't be a delay. I think now the A/V buffer gets "locked?"

I will do some research. In the mean time keep an eye on Debian (rpi is based on this, not Ubuntu?). If it updates the version I suppose the commit will have to be reverted until a fix can be found. That, or better logic for when to play/pause.

fduncanh · 2024-04-21T19:23:37Z

Debian is more conservative. Debian Bookworm is 1.22.0. Debian Sid (Debian development) will be playing with gstreamer-1.24.

Arch is out "in front" with 1.24 immediate after its release. Last time I booted it, Manjaro (Arch derivative) was still in 1.22.10.

Ubuntu is Debian based, but takes stuff from Debian "Sid" as it matures. I suppose ~~Debian~~ Ubuntu 24.10 will have 1.24

The solution to the pause resume issue may be to delay sending the PPS + SPS NAL unit until the resume is confirmed.
The symptom, of the issue are:

failure to find the Xwindow in 5 tries
failure to use the pps+sps nalu to start decoding the video stream

failure 1 doesn't happen if uxplay is compiled without X11 support, so it is incidental.

(a different issue, invalid ntp time, may or may not be related to the pause/resume issue)

fduncanh · 2024-04-22T06:00:40Z

@thiccaxe

I added detection of GStreamer>=1.24 to the CMakelists.txt: GST_124 is defined if 1.24 or later is detected.

I thought that just enclosing the calls to video_pause, video_resume in #ifndef GST_124 ... #endif
would be a temporary fix. but it seems not.

In any case, whatever the fix is, GST_124 works and can be used.

fduncanh · 2024-04-22T22:26:32Z

@thiccaxe

I released UxPlay-1.68.3 with a quick fix which just skips your code if gstreamer 1.24 or later is found at compile time.

I couldnt see any delays when I disabled the code (in the callbacks in uxplay.cpp) (I used an ipad not an iphone though)
Maybe you could check if the original delay problem comes back if the code is disabled.

Instructions on how to trigger it would be useful if its still there

thiccaxe · 2024-04-22T22:29:24Z

Yep maybe those 3 commits from gst even fixed the problem altogether.

fduncanh · 2024-04-22T22:31:43Z

I didn't manage to see the issue using gstreammer-1.22.0 either. It would be good to check if its still there in that case.

Edit: I now saw it in 1.22.0

thiccaxe · 2024-04-22T22:39:34Z

Issue still seems to be there in 1.22.0 (1.22.9 specifically)

thiccaxe · 2024-04-22T22:40:36Z

how did you link the custom gstreamer version to uxplay? Some sort of flag on make or in the cmakelists?

Oh looks like it is as easy as using the "./gst-env.py" script

fduncanh · 2024-04-22T23:36:44Z

To build "my own" gstreamer-1.24, without killing my distro one:

I had to disable the gst-plugins-bad aja plugin

(1) uninstall gstreamer1.0-dev and gstreamer-plugins-base1.0-dev
(2)  update meson:  pip3 install meson     (install as user)
(3) git clone https://gitlab.freedesktop.org/gstreamer/gstreamer
(4) cd gstreamer; git checkout 1.24
(5) meson setup -Dprefix=/home/<username>/gstreamer-1.24 -Dgst-plugins-bad:aja=disable build
(6) cd build ; ninja
(7)   (after finished building) meson install
(8) edit /etc/ld.so.conf   to add /home/<username/gstreamer-1.24/lib     (and lib64)   ; sudo ldconfig
(9) export PATH=$HOME/gstreamer-1.24/bin:$PATH
(10)  rm -rf $HOME/.cache/gstreamer-1.0
(11) which gst-inspect-1.0       (should be the one you built)
(12) gst-inspect-1.0

now build UxPlay (pull latest)

export GSTREAMER_ROOT_DIR=$HOME/gstreamer-1.24/lib64       (path to gstreamer-1.0 directory)
cd 
cd UxPlay
cd build
cmake ..
make
ldd ./uxplay | grep gstreamer    should show its linked to your special gstreamer

thiccaxe · 2024-04-23T00:34:22Z

the fix is pretty simple we simply only pause if the current state is playing,
and only resume if the current state is paused AND we have called the pause function before.

its not 100%, some small delay is there afterwards.

fduncanh · 2024-04-23T01:15:02Z

great!

thiccaxe · 2024-04-23T02:20:55Z

Nevermind, it all breaks if video orientation is changed.

thiccaxe · 2024-04-23T02:22:33Z

It's actually somewhat of a miracle that fix in #209 even worked (I never tested changing screen orientation, I don't know if you did). There is no way to actually know if the airplay client stops streaming except for checking for the absence of video packets.

fduncanh · 2024-04-23T04:55:04Z

as the client goes to sleep it seems to send an unencrypted PPS+SPS NAL unit, and send another one when it restarts

right now these NALs are held back and prepended to the next encrypted video data NAL. will need to check what happens in the code when two unencrypted NALs in a row are sent.

fduncanh · 2024-04-24T15:44:55Z

unfortunately Ubuntu-24.04 beta shows that it ships with gstreamer-1.24.2 and uxplay-1.68.2.

I posted a ubuntu bug report suggesting upgrade to 1.68.3

thiccaxe · 2024-04-24T17:10:07Z

Looks like Fedora 40 would still use 1.22. General release for 40 is still a while away as well.

fduncanh · 2024-09-30T05:22:31Z

@thiccaxe

I would like to clean up this old issue: (1) is it still there (in uxplay-1.70 on git hub.)?

can we write down a precise description of what the problem is? I never fully understood it.

fduncanh · 2024-09-30T06:31:24Z

looking at your old debug trace:

when the client went to sleep, got this: ("header" is bits 4-7 of header, after length (bits 0-3) and timestamp (bits 8-15))

Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01 ts_client = 82600.210022

when the client woke up 7.67 secs later, got this:

Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01 ts_client = 82607.882899

Most of the time unencrypted pps+sps packets have header header bit 6 0x16 by occasionally they have code 0x56:

From raop_rtp_mirror.c :


           
	    /* packet[4] + packet[5] identify the payload type:   values seen are:               *
             * 0x00 0x00: encrypted packet containing a non-IDR  type 1 VCL NAL unit             *
             * 0x00 0x10: encrypted packet containing an IDR type 5 VCL NAL unit                 *
             * 0x01 0x00: unencrypted packet containing a type 7 SPS NAL + a type 8 PPS NAL unit *
             * 0x02 0x00: unencrypted packet (old protocol) no payload, sent once every second   *
             * 0x05 0x00  unencrypted packet with a "streaming report", sent once per second.    */

	    /* packet[6] + packet[7] may list a payload "option":    values seen are:            *
             * 0x00 0x00 : encrypted and "streaming report" packets                              *
             * 0x1e 0x00 : old protocol (seen in AirMyPC) no-payload once-per-second packets     *
             * 0x16 0x01 : seen in most unencrypted h264  SPS+PPS packets                        *
             * 0x56 0x01 : occasionally seen in unencrypted h264 SPS+PPS packets (why different?)*
             * 0x1e 0x01 : unencrypted h265/HEVC SPS+PPS packets                                 */

In h265 video its usually 0x1e, and I guess 0x5e as the "special case" analogous to 0x56, that may mean the client went to sleep?. Some checks to confirm that 0x56 means" h264 going to sleep" are needed.

fduncanh · 2024-09-30T13:24:11Z

@thiccaxe

So the theory of the pair of unencrypted h264 video codec info (SPS + PPS) packets before and after client sleep is that the header code bit 6-7 0x56 0x01 packets tells the server that the client went to sleep mode and the code 0x16 0x01 packet that follows later tells the server the client woke up. the difference in time stamps gives the duration of the sleep, and can be used to adjust the video timing relative to audio (gst_video_pipeline_base_time)

(if this is true the code for a h265 stream will be (guess) 0x5e 0x01 (sleep) followed by 0x1e 0x01 (wake)).

would you be able to test this theory?

fduncanh · 2024-09-30T13:54:21Z

maybe its more general that the 0x56 0x01 unencrypted packet signals that the video stream is stopping (for any reason) (client pause, for example).

EDIT: in mirror mode client pause , a copy of the static screen image is probably still being transmitted, but at a much reduced rate in fps, so in mirror mode "pause" means client sleep, and probably the mirror screen should continue to show the frozen image of the screen when client sleep began.

thiccaxe · 2024-09-30T15:16:35Z

copy of the static screen image is probably still being transmitted

I don't recall seeing this. Either ways, I think it can be ignored safely as gstreamer will show the last frame anyway

thiccaxe · 2024-09-30T15:17:10Z

maybe its more general that the 0x56 0x01 unencrypted packet signals that the video stream is stopping (for any reason) (client pause, for example).

Nice find, I will try to reimplement using this marker.

fduncanh · 2024-09-30T17:23:31Z

analysis of your old debug trace:

sometimes there are two 0x56 packets in quick succession as the client goes to sleep
Video frames are separated by 0.033 secs (30fps)

********************
| receiving video stream  
| last ts: 82600.156589
*********************
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82600.210022
no video  (7.67 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01  ts_client = 82607.882899
********************
| receiving video stream
| first ts 82607.882899 
| last ts 82610.526908
*********************
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82610.581833
no video (2.57 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01  ts_client = 82613.557404
**********************
| receiving video stream
| first ts 82613.557404 
| last ts 82614.847690
********************
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82614.866987
no video (0.06 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82614.934005
no video (2.25 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01  ts_client = 82617.184447
*********************
| receiving video stream
| first ts 82617.184447 
| last ts 82618.569301
*********************
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82618.588370
no video (0.07sec)
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82618.656092
novideo  (1.6secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01  ts_client = 82620.058597
*********************
| receiving video  stream
| first ts 82620.058597 
| last ts 82621.703826
*********************
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01  ts_client = 82621.738247
no  video

(end connection )

fduncanh · 2024-09-30T17:47:12Z

when a 0x56 is received, may save the previous video timestamp. The timestamp of the next 0x16 unencripted packet is same as the first new video frame

thiccaxe · 2024-09-30T21:39:01Z

it turns out h265 can be used for older iphones (I think I had connected it to the ethernet/4k streaming).

when h265 streaming stops, it sends header 01 00 5e 01, and when h264 streaming stops it sends 01 00 56 01. there is only a 1 bit difference between the two, which is interesting.

fduncanh · 2024-09-30T23:07:10Z

Aha! exactly as I guessed! so bit map code.

(if this is true the code for a h265 stream will be (guess) 0x5e 0x01 (sleep) followed by 0x1e 0x01 (wake)).

fduncanh · 2024-09-30T23:19:46Z

I wonder why sometimes two ~~0x5e~~ 0x56 packets got sent in rapid succession?

Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01 ts_client = 82614.866987
no video (0.06 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 56 01 ts_client = 82614.934005
no video (2.25 secs)
Received unencrypted codec packet from client: payload_size 36 header 01 00 16 01 ts_client = 82617.184447

thiccaxe · 2024-10-01T01:47:33Z

I don't think it matters from our end. Maybe it wants some sort of ack?
Or, more likely, poor logic from the sender end.

For example, 56 packets get sent with the content on the screen is static, so maybe there are certain instances where ios deems the content to be static by heuristic A, which sends these packets, but other stream-pausing logic uses heuristic B, which is slightly different from heuristic A in this way and that way.

I guess you could sniff actual airplay traffic, but overall it shouldn't matter for uxplay logic, as the second packet wouldn't do anything.

thiccaxe · 2024-10-01T03:31:55Z

h265:
pause: 01 00 5e 01
play: 01 00 1e 01

h264:
pause: 01 00 56 01
play: 01 00 16 01

bitwise analysis of packet[6]:

pause:
5e: 0b1011110
1e: 0b0011110

play:
56: 0b1010110
16: 0b0010110

so this PR can be more or less replaced by

if (packet[6] == 0x56 || packet[6] == 0x5e) {
    raop_rtp_mirror->callbacks.video_pause(raop_rtp_mirror->callbacks.cls);
} else if (packet[6] == 0x16 || packet[6] == 0x1e) {
    raop_rtp_mirror->callbacks.video_resume(raop_rtp_mirror->callbacks.cls);
}

and remove the other call to resume. This should be more consistent (and remove screen orientation change issues?) and more performant, in that we aren't checking if gstreamer is paused every frame. But still only works for gst < 1.24

fduncanh · 2024-10-01T03:57:46Z

But still only works for gst < 1.24

why exactly do we need to pause and resume? . I need to understand the issue we are trying to fix properly, and I dont.

https://gstreamer.freedesktop.org/documentation/additional/design/states.html?gi-language=c

void video_renderer_resume() {
    if (video_renderer_is_paused()) {
        logger_log(logger, LOGGER_DEBUG, "video renderer resumed");
        gst_element_set_state (renderer->pipeline, GST_STATE_PLAYING);
        gst_video_pipeline_base_time = gst_element_get_base_time(renderer->appsrc);
    }
}

bool video_renderer_is_paused() {
    GstState state;
    gst_element_get_state(renderer->pipeline, &state, NULL, 0);
    return (state == GST_STATE_PAUSED);
}

thiccaxe · 2024-10-01T05:37:04Z

it's the clock. pausing stops the gstreamer clock.

fduncanh · 2024-10-01T12:10:51Z

yes, but why exactly do we need to stop the clock?

this is what the renderer does with the video packets::

void video_renderer_render_buffer(unsigned char* data, int *data_len, int *nal_count, uint64_t *ntp_time) {
    GstBuffer *buffer;
    GstClockTime pts = (GstClockTime) *ntp_time; /*now in nsecs */
    //GstClockTimeDiff latency = GST_CLOCK_DIFF(gst_element_get_current_clock_time (renderer->appsrc), pts);
    if (sync) {
        if (pts >= gst_video_pipeline_base_time) {
            pts -= gst_video_pipeline_base_time;
        } else {
            logger_log(logger, LOGGER_ERR, "*** invalid ntp_time < gst_video_pipeline_base_time\n%8.6f ntp_time\n%8.6f base_time",
                       ((double) *ntp_time) / SECOND_IN_NSECS, ((double) gst_video_pipeline_base_time) / SECOND_IN_NSECS);
            return;
        }
    }

If we are running uxplay with "-vsync" (default) we adjust the timestamp (converted to unix time as pts)
to the gstreamer clock

 if (pts >= gst_video_pipeline_base_time) {
            pts -= gst_video_pipeline_base_time;

Your fix adjusts gst_video_pipeline_base_time by getting it from renderer->appsrc when the resume happens.
after "gst_element_set_state (renderer->pipeline, GST_STATE_PLAYING);" This change will not happen instanteously:
and the change in gstreamer-1.24 maybe locked renderer->appsrc until GST_STATE_PLAYING was achieved???
(perhaps we need to wait till we know the change to PLAYING has finished before resetting gst_video_base_time?)

so is the issue that gst_video_base_time does not properly get reset in gstreamer-1.24?

maybe we can adjust this without pause/resume if the video data sent to the renderer tell it that an adjustment is needed ?

Doe the problem only happen if vsync is on when the client sleeps? I am still not entirely sure what should happen when the client wakes.

fduncanh · 2024-10-01T13:12:47Z

@thiccaxe

But still only works for gst < 1.24

did you check this, or just assume this?

I commented out the skip of pause/resume for gstreamer >= 1.24 in uxplay.cpp video_pause and video_resume
and things seem to be working fine (with no other changes) can you check?

I don't know what changed to make the problem "go away". (if it did).

fduncanh · 2024-10-01T13:44:20Z

@thiccaxe

looking at the code, it appears that in UxPlay-1.70 (github master branch) I inadvertently dropped the callback to video pause at the end of dealing with the sps_pps unencrypted type 0x01 packet, so it doesn't use the code of your fix at all at that point. But uxplay seems to behave properly (using gstreamer-1.24.0) when i put the client to sleep and then wake.

can you check to see if you still see any problem in unmodified github master branch when client sleeps/wakes?

fduncanh · 2024-10-01T15:08:07Z

I activated your fix in GStreamer-1.24, and checked.

The state of renderer->pipeline is still PAUSED when the attempt to update the pipeline _base_time is made so I think one needs to wait till its is PLAYING before asking for the base time (the gst-1.24 changes presumably locked pipeline->appsrc (?) during the PAUSED->PLAYING transition?)

another possibility could be to just add the duration of the non-streaming interval to the gst_video_pipeline_base_time?

fduncanh · 2024-10-01T15:44:49Z

I can fix the gst-1.24 issue by calling gst_get_state with a timeout of 100ms after calling gst_set state in video_renderer-resume. this blocks until the state change has finished (or the timeout is exceeded)

fduncanh · 2024-10-02T08:27:47Z

@thiccaxe

I think the issue with gstreamer >=1.24 is fixed now, and your code is cleaned up as you suggested.

(A call to gst_element_get_state after gst_element_set_state allowed a timeout that blocks until the state change
is finished to be set, and that fixed the gst-1.24 issue)

Please verify with latest github master branch.

The h265 addition seems ready for release as uxplay-1.70 now.

pause/resume gstreamer stream when video stream stops/starts

660a2dc

fduncanh merged commit 01ac91b into FDH2:master Sep 5, 2023

fduncanh mentioned this pull request Apr 22, 2024

GStreamer 1.24 problems AND client ntp problems (was:X11 UxPlay Window not found in 5 search attempts) #284

Closed

fduncanh mentioned this pull request Sep 29, 2024

video renderer paused when AirPlay streaming video / screen orientation changed #346

Closed

pause/resume gstreamer stream when video stream stops/starts #209

pause/resume gstreamer stream when video stream stops/starts #209

Conversation

thiccaxe commented Sep 5, 2023

fduncanh commented Apr 21, 2024

thiccaxe commented Apr 21, 2024

fduncanh commented Apr 21, 2024 • edited Loading

fduncanh commented Apr 22, 2024

fduncanh commented Apr 22, 2024 • edited Loading

thiccaxe commented Apr 22, 2024

fduncanh commented Apr 22, 2024 • edited Loading

thiccaxe commented Apr 22, 2024 • edited Loading

thiccaxe commented Apr 22, 2024 • edited Loading

fduncanh commented Apr 22, 2024 • edited Loading

thiccaxe commented Apr 23, 2024

fduncanh commented Apr 23, 2024

thiccaxe commented Apr 23, 2024

thiccaxe commented Apr 23, 2024

fduncanh commented Apr 23, 2024

fduncanh commented Apr 24, 2024 • edited Loading

thiccaxe commented Apr 24, 2024

fduncanh commented Sep 30, 2024

fduncanh commented Sep 30, 2024

fduncanh commented Sep 30, 2024

fduncanh commented Sep 30, 2024 • edited Loading

thiccaxe commented Sep 30, 2024

thiccaxe commented Sep 30, 2024

fduncanh commented Sep 30, 2024 • edited Loading

fduncanh commented Sep 30, 2024

thiccaxe commented Sep 30, 2024

fduncanh commented Sep 30, 2024

fduncanh commented Sep 30, 2024 • edited Loading

thiccaxe commented Oct 1, 2024

thiccaxe commented Oct 1, 2024

fduncanh commented Oct 1, 2024

thiccaxe commented Oct 1, 2024

fduncanh commented Oct 1, 2024 • edited Loading

fduncanh commented Oct 1, 2024

fduncanh commented Oct 1, 2024 • edited Loading

fduncanh commented Oct 1, 2024 • edited Loading

fduncanh commented Oct 1, 2024

fduncanh commented Oct 2, 2024

fduncanh commented Apr 21, 2024 •

edited

Loading

fduncanh commented Apr 22, 2024 •

edited

Loading

fduncanh commented Apr 22, 2024 •

edited

Loading

thiccaxe commented Apr 22, 2024 •

edited

Loading

thiccaxe commented Apr 22, 2024 •

edited

Loading

fduncanh commented Apr 22, 2024 •

edited

Loading

fduncanh commented Apr 24, 2024 •

edited

Loading

fduncanh commented Sep 30, 2024 •

edited

Loading

fduncanh commented Sep 30, 2024 •

edited

Loading

fduncanh commented Sep 30, 2024 •

edited

Loading

fduncanh commented Oct 1, 2024 •

edited

Loading

fduncanh commented Oct 1, 2024 •

edited

Loading

fduncanh commented Oct 1, 2024 •

edited

Loading