module-raop-sink: Drop the RTSP FLUSH request
I noticed the following in the raop module's log output when I, while watching a Youtube video, jump to another part of the video. Similar things happen when changing tracks in e.g. Spotify.
I added a couple of pw_log_error to make things clearer:
logs
[E][83693.364884] mod.raop-sink | [module-raop-sink: 1649 stream_state_changed()] raop stream state changed: 2
[E][83693.364921] mod.raop-sink | [module-raop-sink: 960 rtsp_do_flush()] entered rtsp_do_flush
[I][83693.365010] default | [ rtsp-client.c: 414 flush_output()] sent: FLUSH rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 9
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Range: npt=0-
RTP-Info: seq=7624;rtptime=2093422847
[I][83693.368828] default | [ rtsp-client.c: 246 process_status()] status: RTSP/1.0 200 OK
[I][83693.368943] default | [ rtsp-client.c: 322 process_header()] Date: Mon, 09 Oct 2023 04:36:58 GMT
[I][83693.368953] default | [ rtsp-client.c: 322 process_header()] Content-Length: 0
[I][83693.368960] default | [ rtsp-client.c: 322 process_header()] RTP-Info: rtptime=2093348223
[I][83693.368966] default | [ rtsp-client.c: 322 process_header()] Server: AirTunes/710.79.1
[I][83693.368975] default | [ rtsp-client.c: 322 process_header()] CSeq: 9
[I][83693.368986] default | [ rtsp-client.c: 279 dispatch_handler()] received reply to request with cseq:9
[I][83693.368999] mod.raop-sink | [module-raop-sink: 952 rtsp_log_reply_status()] reply status: 200
[E][83693.746093] mod.raop-sink | [module-raop-sink: 1649 stream_state_changed()] raop stream state changed: 3
[E][83693.746328] mod.raop-sink | [module-raop-sink: 1051 rtsp_do_record()] entered rtsp_do_record
[I][83693.746542] default | [ rtsp-client.c: 414 flush_output()] sent: RECORD rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 10
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Range: npt=0-
RTP-Info: seq=7624;rtptime=2093422847
[E][83693.749653] mod.raop-sink | [module-raop-sink: 1649 stream_state_changed()] raop stream state changed: 2
[E][83693.749691] mod.raop-sink | [module-raop-sink: 960 rtsp_do_flush()] entered rtsp_do_flush
[E][83693.750224] mod.raop-sink | [module-raop-sink: 1649 stream_state_changed()] raop stream state changed: 3
[E][83693.750249] mod.raop-sink | [module-raop-sink: 1051 rtsp_do_record()] entered rtsp_do_record
[I][83693.750292] default | [ rtsp-client.c: 414 flush_output()] sent: RECORD rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 11
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Range: npt=0-
RTP-Info: seq=7624;rtptime=2093422847
[I][83693.796944] default | [ rtsp-client.c: 246 process_status()] status: RTSP/1.0 500 Internal Server Error
[I][83693.797083] default | [ rtsp-client.c: 322 process_header()] Content-Length: 0
[I][83693.797115] default | [ rtsp-client.c: 322 process_header()] Server: AirTunes/710.79.1
[I][83693.797127] default | [ rtsp-client.c: 322 process_header()] CSeq: 10
[I][83693.797139] default | [ rtsp-client.c: 279 dispatch_handler()] received reply to request with cseq:10
[I][83693.797160] mod.raop-sink | [module-raop-sink: 1009 rtsp_record_reply()] record status: 500
[I][83693.797292] default | [ rtsp-client.c: 414 flush_output()] sent: SET_PARAMETER rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 12
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Content-Type: text/parameters
Content-Length: 20
volume: -25.542755
[I][83693.797311] default | [ rtsp-client.c: 414 flush_output()] sent: SET_PARAMETER rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 13
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Content-Type: text/parameters
Content-Length: 17
progress: 0/0/0
[I][83693.806507] default | [ rtsp-client.c: 246 process_status()] status: RTSP/1.0 500 Internal Server Error
[I][83693.806692] default | [ rtsp-client.c: 322 process_header()] Content-Length: 0
[I][83693.806703] default | [ rtsp-client.c: 322 process_header()] Server: AirTunes/710.79.1
[I][83693.806714] default | [ rtsp-client.c: 322 process_header()] CSeq: 11
[I][83693.806729] default | [ rtsp-client.c: 279 dispatch_handler()] received reply to request with cseq:11
[I][83693.806742] mod.raop-sink | [module-raop-sink: 1009 rtsp_record_reply()] record status: 500
[I][83693.806852] default | [ rtsp-client.c: 414 flush_output()] sent: SET_PARAMETER rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 14
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Content-Type: text/parameters
Content-Length: 20
volume: -25.542755
[I][83693.806870] default | [ rtsp-client.c: 414 flush_output()] sent: SET_PARAMETER rtsp://192.168.2.20/3223075171 RTSP/1.0
CSeq: 15
Client-Instance: 59A7511E8E461ABD
DACP-ID: 59A7511E8E461ABD
User-Agent: PipeWire/0.3.81
Session: 1
Content-Type: text/parameters
Content-Length: 17
progress: 0/0/0
[I][83693.894196] default | [ rtsp-client.c: 246 process_status()] status: RTSP/1.0 200 OK
[I][83693.894967] default | [ rtsp-client.c: 322 process_header()] Date: Mon, 09 Oct 2023 04:36:59 GMT
[I][83693.895029] default | [ rtsp-client.c: 322 process_header()] Content-Length: 0
[I][83693.895085] default | [ rtsp-client.c: 322 process_header()] Server: AirTunes/710.79.1
[I][83693.895138] default | [ rtsp-client.c: 322 process_header()] CSeq: 12
[I][83693.895196] default | [ rtsp-client.c: 279 dispatch_handler()] received reply to request with cseq:12
[I][83693.895257] mod.raop-sink | [module-raop-sink: 952 rtsp_log_reply_status()] reply status: 200
So what appears to be happening is the following: First, the stream state changes to PAUSED, RTSP FLUSH is sent, impl->recording is set to false. Then in very quick succession, the stream state changes to STREAMING, back to PAUSED again, then to STREAMING again, leading to a new RECORD request (which is already wrong), no new FLUSH is sent this time as recording == false, and then a second RECORD request (definitely wrong).
The Apple HomePod I'm using does not seem to like the RECORD requests, replying with RTSP/1.0 500 Internal Server Error.
The stream does pick up after that, although a small pause in playback is noticeable.
My proposed solution to this is to remove the FLUSH request althogether. It does not seem to be required, instead it sounds like something needed when doing buffered streaming, which PW does not.
This change also makes track changes etc much more snappy, as there's no pause in playback anymore.