minisatip icon indicating copy to clipboard operation
minisatip copied to clipboard

[Q] satipc: 503 Service Unavailable

Open lars18th opened this issue 4 years ago • 0 comments

Hi @catalinii ,

I have one question for you:

  • One of my SAT>IP servers (a Mirage based STB) responds time to time with the error "503 Service Unavailable" to some RTSP commands. More or less the problem is when the previous tunning not completes (the tuner is slow to lock the signal), and the next try to tune another transponder generates the trouble.

Here a simplified LOG of the problem (the SAT>IP client is a simple HTTP wget; the SAT>IP server is 192.168.1.43; and minisatip is 192.168.1.37):

[...]

[10/11 14:29:35.019 main]: satipc: commit for adapter 4 freq 11347000, pids to add 6, pids to delete 0, expect_reply 0, force_commit 1 want_tune 1 do_tune 1, force_pids 0, sent_transport 0, sleep 1, closed_rtsp 0
[10/11 14:29:35.019 main]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.019 main]: MSG process >> server :
SETUP rtsp://192.168.1.43:554/?src=1&freq=11347&msys=dvbs&mtype=qpsk&pol=v&sr=22000&pids=none RTSP/1.0
CSeq: 109
Transport: RTP/AVP;unicast;client_port=6508-6509


[10/11 14:29:35.020 main]: Reply (handle 10) [192.168.1.38:54127] content_len:0, sock 10
[10/11 14:29:35.020 main]: MSG client << process :
HTTP/1.0 200 OK
Date: Wed, Nov 10 13:29:35 2021 GMT
Server: minisatip/1.1.47
Content-Type: video/mp2t
Connection: close


[10/11 14:29:35.020 main]: Mutex init OK 0x7f2ff49e7488

[...]

[10/11 14:29:35.022 AD1]: satipc: Received signal status from the server for adapter 1, stength=226 status=1 snr=11
[10/11 14:29:35.118 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.118 AD4]: MSG process << server :
RTSP/1.0 200 OK
CSeq: 109
Date: Wed, Nov 10 2021 14:16:15 GMT
Transport: RTP/AVP;unicast;destination=192.168.1.37;source=192.168.1.43;client_port=6508-6509;server_port=6974-6975
Session: EDCD7C81;timeout=60
com.ses.streamID: 308


[10/11 14:29:35.118 AD4]: satipc: session set for adapter 4 to EDCD7C81
[10/11 14:29:35.118 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 6, pids to delete 0, expect_reply 0, force_commit 1 want_tune 0 do_tune 0, force_pids 0, sent_transport 1, sleep 1, closed_rtsp 0
[10/11 14:29:35.118 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.118 AD4]: MSG process >> server :
PLAY rtsp://192.168.1.43:554/stream=308?addpids=0,16,17,18,5167,5171 RTSP/1.0
CSeq: 110
Session: EDCD7C81


[10/11 14:29:35.209 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.209 AD4]: MSG process << server :
RTSP/1.0 503 Service Unavailable
CSeq: 110
Date: Wed, Nov 10 2021 14:16:15 GMT


[10/11 14:29:35.209 AD4]: satipc 0 wp 0 qp 0, expect_reply 1, want_tune 1, force_commit 1, want commit 1
[10/11 14:29:35.209 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 0, pids to delete 0, expect_reply 0, force_commit 1 want_tune 1 do_tune 0, force_pids 0, sent_transport 0, sleep 0, closed_rtsp 0
[10/11 14:29:35.209 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.209 AD4]: MSG process >> server :
SETUP rtsp://192.168.1.43:554/?src=1&freq=11347&msys=dvbs&mtype=qpsk&pol=v&sr=22000&pids=none RTSP/1.0
CSeq: 111
Transport: RTP/AVP;unicast;client_port=6508-6509


[10/11 14:29:35.315 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.315 AD4]: MSG process << server :
RTSP/1.0 200 OK
CSeq: 111
Date: Wed, Nov 10 2021 14:16:15 GMT
Transport: RTP/AVP;unicast;destination=192.168.1.37;source=192.168.1.43;client_port=6508-6509;server_port=6976-6977
Session: D5C05BAB;timeout=60
com.ses.streamID: 309


[10/11 14:29:35.315 AD4]: satipc: session set for adapter 4 to D5C05BAB
[10/11 14:29:35.315 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 0, pids to delete 0, expect_reply 0, force_commit 1 want_tune 0 do_tune 0, force_pids 0, sent_transport 1, sleep 0, closed_rtsp 0
[10/11 14:29:35.315 AD4]: satipc: nothing to commit
[10/11 14:29:35.315 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.315 AD4]: MSG process >> server :
PLAY rtsp://192.168.1.43:554/stream=309?addpids=0,16,17,18,5167,5171 RTSP/1.0
CSeq: 112
Session: D5C05BAB


[10/11 14:29:35.405 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.405 AD4]: MSG process << server :
RTSP/1.0 503 Service Unavailable
CSeq: 112
Date: Wed, Nov 10 2021 14:16:15 GMT


[10/11 14:29:35.405 AD4]: satipc 0 wp 0 qp 0, expect_reply 1, want_tune 1, force_commit 1, want commit 1
[10/11 14:29:35.405 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 0, pids to delete 0, expect_reply 0, force_commit 1 want_tune 1 do_tune 0, force_pids 0, sent_transport 0, sleep 0, closed_rtsp 0
[10/11 14:29:35.405 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.405 AD4]: MSG process >> server :
SETUP rtsp://192.168.1.43:554/?src=1&freq=11347&msys=dvbs&mtype=qpsk&pol=v&sr=22000&pids=none RTSP/1.0
CSeq: 113
Transport: RTP/AVP;unicast;client_port=6508-6509


[10/11 14:29:35.499 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.499 AD4]: MSG process << server :
RTSP/1.0 200 OK
CSeq: 113
Date: Wed, Nov 10 2021 14:16:15 GMT
Transport: RTP/AVP;unicast;destination=192.168.1.37;source=192.168.1.43;client_port=6508-6509;server_port=6978-6979
Session: 5988B028;timeout=60
com.ses.streamID: 310


[10/11 14:29:35.499 AD4]: satipc: session set for adapter 4 to 5988B028
[10/11 14:29:35.499 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 0, pids to delete 0, expect_reply 0, force_commit 1 want_tune 0 do_tune 0, force_pids 0, sent_transport 1, sleep 0, closed_rtsp 0
[10/11 14:29:35.499 AD4]: satipc: nothing to commit
[10/11 14:29:35.499 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.499 AD4]: MSG process >> server :
PLAY rtsp://192.168.1.43:554/stream=310?addpids=0,16,17,18,5167,5171 RTSP/1.0
CSeq: 114
Session: 5988B028


[10/11 14:29:35.603 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.603 AD4]: MSG process << server :
RTSP/1.0 503 Service Unavailable
CSeq: 114
Date: Wed, Nov 10 2021 14:16:15 GMT


[10/11 14:29:35.603 AD4]: satipc 0 wp 0 qp 0, expect_reply 1, want_tune 1, force_commit 1, want commit 1
[10/11 14:29:35.603 AD4]: satipc: commit for adapter 4 freq 11347000, pids to add 0, pids to delete 0, expect_reply 0, force_commit 1 want_tune 1 do_tune 0, force_pids 0, sent_transport 0, sleep 0, closed_rtsp 0
[10/11 14:29:35.603 AD4]: satipc_http_request (adapter 4): sending to sock 13
[10/11 14:29:35.603 AD4]: MSG process >> server :
SETUP rtsp://192.168.1.43:554/?src=1&freq=11347&msys=dvbs&mtype=qpsk&pol=v&sr=22000&pids=none RTSP/1.0
CSeq: 115
Transport: RTP/AVP;unicast;client_port=6508-6509


[10/11 14:29:35.697 AD4]: satipc_reply (adapter 4): receiving from handle 13, sock 13
[10/11 14:29:35.697 AD4]: MSG process << server :
RTSP/1.0 200 OK
CSeq: 115
Date: Wed, Nov 10 2021 14:16:15 GMT
Transport: RTP/AVP;unicast;destination=192.168.1.37;source=192.168.1.43;client_port=6508-6509;server_port=6980-6981
Session: D3B41F24;timeout=60
com.ses.streamID: 311

[...]

As you can see the problem is this: The SAT>IP server responds with OK to the SETUP command. But for the next PLAY command, it generates a response with the 503 error. And the "satipc" module restarts then with a new SETUP, and this triggers a loop of SETUP->OK->PLAY->503->... until the SAT>IP client stops to try to tune. That's the only solution to break the loop: close the tuner.

So, the question is this: You think it's possible to send a TEARDOWN when a 503 error is received, wait some miliseconds and then send the SETUP? The idea of the workaround is to instruct to the SAT>IP server to close the tuner before opening it another time with a SETUP. You feel this will be complex to implement it?

Please, comment about this. Thank you!

lars18th avatar Nov 10 '21 13:11 lars18th