[Live-devel] When streaming RTP over TCP, Live555 Proxy Server sometimes does not reconnect to 'back end' device
Erik Montnemery
erik at montnemery.com
Mon Dec 26 08:03:16 PST 2016
Hi,
Most of the time, the proxy server reconnects to the 'back-end' server
after an error or loss of connection, but every now and then the
following happens:
Error or connection loss is detected, and the reset sequence is performed.
However, after the new connection to the 'back end' server is
initiated but before it is established, the socket's background
handler is reset and the reestablish of the connection to the 'back
end' server is thus hung forever:
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 255)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::deregisterRTPInterface setting fDeleteMyselfNext
^-- fDeleteMyselfNext is set
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 2)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[(NULL)]: Calling setBaseURL(fOurURL)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://root:xxxxxx@192.168.0.35/axis-media/media.amp]:
Calling sendDESCRIBE(this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient::sendDESCRIBE rtspClient == NULL: FALSE
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::sendRequest
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - we need to open a connection
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::openConnection
Dec 26 16:20:15 Thor live555ProxyServer[27609]: Opening connection to
192.168.0.35, port 554...
Dec 26 16:20:15 Thor live555ProxyServer[27609]: Setting up
BackgroundHandling for socket 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::connectToServer setBackgroundHandling(5,
SOCKET_WRITABLE|SOCKET_EXCEPTION, connectionHandler, this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, c, 0x40a250, 0x10b6430)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - connectResult:0
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - connectionIsPending:1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://root:xxxxxx@192.168.0.35/axis-media/media.amp]:
Reset done
^-- Reset sequence in ProxyRTSPClient::continueAfterLivenessCommand finished
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::tcpReadHandler fDeleteMyselfNext set
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::~SocketDescriptor turnOffBackgroundReadHandling(5)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, 0, 0x0, 0x0)
^-- Background handler reset again before the connection is reestablished
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::handleAlternativeRequestByte1 setBackgroundHandling(5,
SOCKET_READABLE|SOCKET_EXCEPTION, incomingDataHandler, this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, a, 0x40d4f0, 0x10b6430)
I guess the problem is related to the reset sequence being run from
within SocketDescriptor::tcpReadHandler?
More context:
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://192.168.0.35/axis-media/media.amp/]: lost
connection to server ('errno': -2). Resetting...
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://192.168.0.35/axis-media/media.amp/]: Calling
reset
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://192.168.0.35/axis-media/media.amp/]:
ProxyRTSPClient::reset enter
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::reset
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::resetTCPSockets
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::resetTCPSockets disableBackgroundHandling(5) 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[(NULL)]: ProxyRTSPClient::reset leave
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[(NULL)]: Calling
fOurServerMediaSession.resetDESCRIBEState()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPServer::RTSPClientSession(0x17eea90)::~RTSPClientSession
session(0x10b6210)->referenceCount(): 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 2
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 9
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 9)::deregisterRTPInterface(channel 0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 9
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 9)::deregisterRTPInterface(channel 1)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 3
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream()
streamState(0x17eea20)->referenceCount(): 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 4
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
StreamState(0x17eea20)::~StreamState()
Dec 26 16:20:15 Thor live555ProxyServer[27609]: StreamState::reclaim()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading turnOffBackgroundReadHandling(28)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(28, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),H264]::closeStreamSource()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),H264]::closeStreamSource()
fParentSession(0x10b6210)->refcnt: 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),H264]::closeStreamSource()
subsession: (0) port:52784, codecName: H264, hasRTPSource: YES
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),H264]::closeStreamSource()
subsession: (1) port:43362, codecName: MPEG4-GENERIC, hasRTPSource:
YES
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 6
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 2
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 9
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 9)::deregisterRTPInterface(channel 2)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 9
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 9)::deregisterRTPInterface(channel 3)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::deregisterRTPInterface calling delete
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::~SocketDescriptor turnOffBackgroundReadHandling(9)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(9, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(9, a, 0x402d1a, 0x189b340)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 3
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream()
streamState(0x1894570)->referenceCount(): 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 4
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
StreamState(0x1894570)::~StreamState()
Dec 26 16:20:15 Thor live555ProxyServer[27609]: StreamState::reclaim()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading turnOffBackgroundReadHandling(31)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(31, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 2)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),MPEG4-GENERIC]::closeStreamSource()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),MPEG4-GENERIC]::closeStreamSource()
fParentSession(0x10b6210)->refcnt: 1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),MPEG4-GENERIC]::closeStreamSource()
subsession: (0) port:52784, codecName: H264, hasRTPSource: YES
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),MPEG4-GENERIC]::closeStreamSource()
subsession: (1) port:43362, codecName: MPEG4-GENERIC, hasRTPSource:
YES
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
OnDemandServerMediaSubsession::deleteStream() 6
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
GenericMediaServer::ClientSession::~ClientSession
fOurServerMediaSession(0x10b6210)->referenceCount(): 0
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),H264]::~ProxyServerMediaSubsession()
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyServerMediaSubsession[(NULL),MPEG4-GENERIC]::~ProxyServerMediaSubsession()
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 255)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::deregisterRTPInterface setting fDeleteMyselfNext
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 255)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::deregisterRTPInterface setting fDeleteMyselfNext
^-- fDeleteMyselfNext is set
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTPInterface::stopNetworkReading
turnOffBackgroundReadHandling(4294967295)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(4294967295, 0, 0x0, 0x0)
Dec 26 16:20:15 Thor live555ProxyServer[27609]: deregisterSocket sockNum: 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor(socket 5)::deregisterRTPInterface(channel 2)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[(NULL)]: Calling setBaseURL(fOurURL)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://root:xxxxxx@192.168.0.35/axis-media/media.amp]:
Calling sendDESCRIBE(this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient::sendDESCRIBE rtspClient == NULL: FALSE
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::sendRequest
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - we need to open a connection
Dec 26 16:20:15 Thor live555ProxyServer[27609]: RTSPClient::openConnection
Dec 26 16:20:15 Thor live555ProxyServer[27609]: Opening connection to
192.168.0.35, port 554...
Dec 26 16:20:15 Thor live555ProxyServer[27609]: Setting up
BackgroundHandling for socket 5
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::connectToServer setBackgroundHandling(5,
SOCKET_WRITABLE|SOCKET_EXCEPTION, connetionHandler, this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, c, 0x40a250, 0x10b6430)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - connectResult:0
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::sendRequest - connectionIsPending:1
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
ProxyRTSPClient[rtsp://root:xxxxxx@192.168.0.35/axis-media/media.amp]:
Reset done
^-- Reset sequence in ProxyRTSPClient::continueAfterLivenessCommand finished
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::tcpReadHandler fDeleteMyselfNext set
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
SocketDescriptor::~SocketDescriptor turnOffBackgroundReadHandling(5)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, 0, 0x0, 0x0)
^-- Background handler reset again before the connection is reestablished
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
RTSPClient::handleAlternativeRequestByte1 setBackgroundHandling(5,
SOCKET_READABLE|SOCKET_EXCEPTION, incomingDataHandler, this)
Dec 26 16:20:15 Thor live555ProxyServer[27609]:
BasicTaskScheduler::setBackgroundHandling(5, a, 0x40d4f0, 0x10b6430)
Dec 26 16:20:20 Thor live555ProxyServer[27609]:
RTSPServer::RTSPClientConnection(0x189b340)::~RTSPClientConnection
Dec 26 16:20:20 Thor live555ProxyServer[27609]:
RTSPServer::RTSPClientConnection(0x189b340)::closeSocketsRTSP
Dec 26 16:20:20 Thor live555ProxyServer[27609]:
GenericMediaServer::ClientConnection::closeSockets
disableBackgroundHandling(9)
/Erik
More information about the live-devel
mailing list