UxPlay opens... then closes after a short while, streaming video and audio.

STrRedWolf commented 1 year ago

...a short while being under a minute. Here's the debug log. Streaming from a 3rd gen 11" iPad Pro running iOS 16.2 to a Linux Mint 21.1 system (read: Ubuntu w/o snap).

debug.log

fduncanh commented 1 year ago

Hmm. You crashed after 5 secs video, no audio. No idea why this happened. You`ll need to investigate. Could be a network problem. (message was "mirror tcp socket is closed")

uxplay generally works fine

Does it always happen ? every time? did you see any video during that 5 secs?
does it happen with older versions of uxplay? (1.63 is just released, try 1.62 and let us know)
what uxplay options are you using, if any?

raop_rtp video: now = 1677116195.294648, ntp = 1677116195.382605, latency = -0.087957, ts = 2026434.349601, 00 00 00 0
raop_rtp_mirror tcp socket is closed, got 0 bytes of 128 byte header
httpd receiving on socket 24
conn_request

fduncanh commented 1 year ago

I tested on Ubuntu 22.04.1 LTS, which Mint Vera 21.1 is based on, and uxplay-1.63 works just fine there.

If you give more details, maybe we can work out what your issue is.

STrRedWolf commented 1 year ago

Sorry about that, I just got off work and it's the first time I'm able to respond.

Always happens. Every time. I do see video during those 5 seconds. Also happens on 1.46 (which is on Ubuntu) and 1.63.1 (yes, I compiled a fresh 1.63.2 just in case). I'm just executing "uxplay" normally... and the ufw (Ubuntu Firewall) system is inactive.

fduncanh commented 1 year ago

You made it through the decryption handshake and all that. so not a firewall issue.

Is it always 5 secs after video starts? that the "tcp socket is closed" causes a TEARDOWN?

streaming starts at (seconds after 01.01.1970) 1677116190.577717,

Begin streaming to GStreamer video pipeline
Looking for X11 UxPlay Window, attempt 1
raop_rtp video: now = 1677116190.577717, ntp = 1677116190.588988, latency = -0.011271, ts = 2026429.555985, 00 00 00 00 
Looking for X11 UxPlay Window, attempt 2

*** X11 Windows: Use key F11 or (left Alt)+Enter to toggle full-screen mode

raop_rtp video: now = 1677116190.584535, ntp = 1677116190.630672, latency = -0.046137, ts = 2026429.597668, 00 00 00 00 
raop_rtp video: now = 1677116190.584548, ntp = 1677116190.664018, latency = -0.079470, ts = 2026429.631015, 00 00 00 00

just under 5 secs later, at 1677116195.394368

raop_rtp video: now = 1677116195.394368, ntp = 1677116195.482645, latency = -0.088277, ts = 2026434.449641, 00 00 00 00 
raop_rtp_mirror tcp socket is closed, got 0 bytes of 128 byte header

*what follows seems to be a type 110 teardown request FROM THE CLIENT!!! saying it is shutting down the video stream,

httpd receiving on socket 24
conn_request

TEARDOWN rtsp://192.168.1.4/10176044275597789477 RTSP/1.0
Content-Length: 69
Content-Type: application/x-apple-binary-plist
CSeq: 15
DACP-ID: C5FD4E07DD88B773
Active-Remote: 1396166701
User-Agent: AirPlay/670.6.2

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>streams</key>
    <array>
        <dict>
            <key>type</key>
            <integer>110</integer>
        </dict>
    </array>
</dict>
</plist>

Handling request TEARDOWN with URL rtsp://192.168.1.4/10176044275597789477
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>streams</key>
    <array>
        <dict>
            <key>type</key>
            <integer>110</integer>
        </dict>
    </array>
</dict>
</plist>

TEARDOWN request,  96=0, 110=1
raop_rtp_mirror->running is no longer true
raop_rtp_mirror exiting TCP thread

During the 5 secs, you received 4 reports from the client (once per second)

Received video streaming performance info packet from client: payload_size 25364 header 05 00 00 00  ts_raw = 0

Use option -FPSdata to see what they are saying. The all have a 25000 byte file attached to it (as well as the performance data) that I dont know what it means, I never got around to understanding those extra 25000 bytes but it might be some kind of request or demand that should be displayed on the AppleTV screen, but uxplay ignores it. (like maybe, client is saying enter some code within the next 5 secs or you will be cut off!). Is your ipad/iphone something that might have corporate MDM ("mobile device management" locked on to it?)

Also, please see if audio-only mode works for you.

If you want, I will see if I can add a feature to a "testing" version of uxplay that you could download to maybe capture that 25000byte unknown message. I'm curious.

STrRedWolf commented 1 year ago

Here's what uxplay -FPSdata says.

debug2.log

Audio only has the same effect.

uxplay -vs 0 -d... debug3.txt

uxplay -vs 0 -FPSdata debug4.txt

An added datapoint: I'm using an eero Wifi mesh router set to bridge. Worse comes to worse, I got a spare Pi Zero W that I'll turn into a Wifi bridge to see if the eero is causing issues.

STrRedWolf commented 1 year ago

And no, this isn't a corporate MDM'ed iPad Pro. My own, bought from AT&T.

fduncanh commented 1 year ago

No for audio only, I mean not -vs 0 but the other way of streaming (a different button on the client not the mirror one , the one for apple music, apple radio etc. looks like a triangular mountain emitting waves

(not vs 0).

STrRedWolf commented 1 year ago

No audio, period. It doesn't switch over, and it does die after a bit on the on-screen log. Captures, first -d, second -FPSdata.

debug5.log debug6.log

fduncanh commented 1 year ago

You ipad is not sending a request to setup audio, it instead shuts down video!

raop_ntp receive time type_t=83 packetlen = 32, now = 1677198895.799516 t1 = 2109136.799010, t2 = 2109136.799085
80 d3 00 07 00 00 00 00 e7 a2 84 af bd d1 8c 42 
83 ca ad 50 cc 8b ea a8 83 ca ad 50 cc 90 d0 0e 

raop_ntp sync correction = 0
httpd receiving on socket 24
conn_request

POST /feedback RTSP/1.0
CSeq: 12
DACP-ID: 1B3DCD2A43827ADA
Active-Remote: 3514449367
User-Agent: AirPlay/670.6.2

Handling request POST with URL /feedback
raop_handler_feedback

RTSP/1.0 200 OK 
CSeq: 12 
Server: AirTunes/220.68 

httpd receiving on socket 24
conn_request

TEARDOWN rtsp://192.168.1.4/2261321184877825426 RTSP/1.0
Content-Length: 42
Content-Type: application/x-apple-binary-plist
CSeq: 13
DACP-ID: 1B3DCD2A43827ADA
Active-Remote: 3514449367
User-Agent: AirPlay/670.6.2

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict/>
</plist>

we need to find out why.

what should happen then is

raop_ntp receive time type_t=83 packetlen = 32, now = 1677199880.533860 t1 = 97177.643713, t2 = 97177.643844
80 d3 00 07 00 00 00 00 e7 a2 88 88 63 6f c3 a1 
83 ab fa 19 a4 ca 5f 58 83 ab fa 19 a4 d2 fc 26 

raop_ntp sync correction = 0
httpd receiving on socket 24
conn_request

POST /feedback RTSP/1.0
CSeq: 12
DACP-ID: C0EC24BE4114410B
Active-Remote: 1017137337
User-Agent: AirPlay/675.4.1

Handling request POST with URL /feedback
raop_handler_feedback

RTSP/1.0 200 OK 
CSeq: 12 
Server: AirTunes/220.68 

httpd receiving on socket 24
conn_request

SETUP rtsp://192.168.2.8/3658165428372654778 RTSP/1.0
Content-Length: 243
Content-Type: application/x-apple-binary-plist
CSeq: 13
DACP-ID: C0EC24BE4114410B
Active-Remote: 1017137337
User-Agent: AirPlay/675.4.1

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
        <key>streams</key>
        <array>
                <dict>
                        <key>latencyMax</key>
                        <integer>88200</integer>
                        <key>sr</key>
                        <integer>44100</integer>
                        <key>audioMode</key>
                        <string>default</string>
                        <key>latencyMin</key>
                        <integer>11025</integer>
                        <key>ct</key>
                        <integer>2</integer>
                        <key>spf</key>
                        <integer>352</integer>
                        <key>controlPort</key>
                        <integer>56202</integer>
                        <key>supportsDynamicStreamID</key>
                        <true/>
                        <key>audioFormat</key>
                        <integer>262144</integer>
                        <key>isMedia</key>
                        <true/>
                        <key>type</key>
                        <integer>96</integer>
                </dict>
        </array>
</dict>
</plist>

Handling request SETUP with URL rtsp://192.168.2.8/3658165428372654778
DACP-ID: C0EC24BE4114410B
Active-Remote: 1017137337
Transport: null
type = 96
ct=2 spf=352 usingScreen=0 isMedia=1  audioFormat=0x40000
start audio connection, format ALAC 44100/16/2
raop_rtp starting audio
raop_rtp local control port socket 32 port UDP 6001
raop_rtp local data port    socket 33 port UDP 6000
RAOP initialized success

STrRedWolf commented 1 year ago

Weird. What iOS version are you testing with? Maybe there's a version difference.

STrRedWolf commented 1 year ago

Just for fun, I also tried to mirror to my TCL Roku TV. First time it asked to pair via 4-digit code… and then went to it’s home menu. I tried again and it froze on the display (I was able to get it back home).

I’m suspecting my iPad Pro’s iOS version is buggy…

fduncanh commented 1 year ago

iOS 16.3

Is been tested with every iOS since 14.x

fduncanh commented 1 year ago

I'm adapting a testing version to look at the 25000byte data, I suspect is a message for the screen

STrRedWolf commented 1 year ago

I just updated to latest, 16.3.1... and it fixed the issue on the iPad Pro side.

I guess iPadOS/iOS 16.2 had a bug in it that was resolved in 16.3.

fduncanh commented 1 year ago

So its fixed, whatever it was?

If so, just close the issue

STrRedWolf commented 1 year ago

Yep. Thanks for the help.

FDH2 / UxPlay

UxPlay opens... then closes after a short while, streaming video and audio. #183