[Pending] - Slow RTSP startup causes EOF indication

Discussion in 'Submit: code patches (MediaPortal/TV-Server/etc.)' started by dmertz, May 10, 2011.

Page 1 of 3

  1. dmertz Portal Member

    Apparently my server can be a bit slow to begin delivering recorded TV via RTSP at times. When this startup delay exceeds 2000 ticks, it causes TsReader's demuxer to declare a premature EOF condition. This causes MP to further misbehave in that MP fails to play the file while continuing to keep the RTSP stream coming, eventually exceeding the maximum allowed amount of buffering. The fix I'm providing here deals with preventing the false EOF at startup, eliminating this particular trigger of the MP hang. This does not include any changes to improve MP's handling of an RTSP EOF at startup; I've only corrected the false EOF.

    CDeMultiplexer.ReadFromFile() declares an EOF if the time since the previous RTSP packet arrived (or, in this case, since the initiation of the RTSP stream) exceeds 2000 ticks. Since CDeMultiplexer.Start() is already capable of making repeated calls to ReadFromFile() to establish an initial amount of buffered data, it makes sense that a premature EOF be ignored. The code change I made simply moves one line of code to cause m_bEndOfFile to be reinitialized to false immediatly prior to each call to ReadFromFile() by Start(). If the final call to ReadFromFile() by Start() results in an EOF indication, the EOF indication remains set.

    I've also increased the time allowed by Start() to initially fill the buffer from 5000 ticks to 10000 ticks. This increase normally has no effect since the initial fill should complete prior to that anyway, but the higher value provides a bit more margin since the premature EOF issue shows that the beginning of streaming can be delayed by at least 2000 ticks.

    I've attached a set of logs made before the code change that show the EOF indication being prematurely set (TsReader log, demux:endoffile) and the subsequent filling of the buffer to maximum because the data is not being consumed. (Ignore the server logs; the client was actually connecting to a server on a different machine.) TsReader logs made after implementing the code change show that recorded-TV playing proceeds normally despite demux:endof file appearing in the log, and the MP hang is avoided.

    The .patch file contains changes to DirectShowFilters\TsReader\DeMultiplexer.cpp.

    Dave

    Attached Files:

    dmertz, May 10, 2011
    Share #1
    • Like Like x 1

  2. sincze Portal Pro

    I have the same issues in MP 1.2. How to apply this fix??
    sincze, September 20, 2011
    Share #2

  3. sincze Portal Pro

    Is this problem still there in MP 1.2.
    It seems I have the same problem

    Log:
    Show Spoiler

    22-09-2011 20:51:46.025 [1dec]---------- v0.4.12 -------------------
    22-09-2011 20:51:46.026 [1dec]CTsReaderFilter::ctor
    22-09-2011 20:51:46.026 [1dec]CRTSPClient::Initialize()
    22-09-2011 20:51:46.026 [1dec]CRTSPClient::createClient()
    22-09-2011 20:51:46.027 [1dec]Slow motion video allowed during zapping
    22-09-2011 20:51:46.027 [1dec]Wait for seeking to eof - false - constructor
    22-09-2011 20:51:46.027 [1dec]SetRelaxedMode
    22-09-2011 20:51:46.028 [1dec]Normal discontinuities filtering
    22-09-2011 20:51:46.028 [1dec]CALLBACK SET
    22-09-2011 20:51:46.028 [1dec]SetRequestAudioChangeCallback SET
    22-09-2011 20:51:46.029 [1dec]CTsReaderFilter::Load()
    22-09-2011 20:51:46.029 [1dec]open rtsp:rtsp://media-PC:554/2E39FE57
    22-09-2011 20:51:46.029 [1dec]CRTSPClient::OpenStream()
    22-09-2011 20:51:46.029 [1dec]CRTSPClient::getSDPDescriptionFromURL()
    22-09-2011 20:51:46.194 [1dec]rangestart:0.000000 rangeend:4017.769000
    22-09-2011 20:51:46.196 [1dec]Created receiver for video MP2T 55142 55143
    22-09-2011 20:51:46.196 [1dec]rtsp:increaseReceiveBufferTo to 2000000 for s:1824
    22-09-2011 20:51:46.197 [1dec]CRTSPClient::setupStreams()
    22-09-2011 20:51:46.197 [1dec]CRTSPClient::clientSetupSubsession()
    22-09-2011 20:51:46.201 [1dec]Setup video MP2T 55142 55143
    22-09-2011 20:51:46.202 [1dec]CMemorySink::ctor
    22-09-2011 20:51:46.202 [1dec]Created output sink:
    22-09-2011 20:51:46.202 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:46.203 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:46.203 [1dec]memorybuffer: run:1 1
    22-09-2011 20:51:46.203 [1dec]memorybuffer: running:1
    22-09-2011 20:51:46.203 [1dec]CRTSPClient::play from 0.000000 / 0.000000
    22-09-2011 20:51:46.204 [1dec]CRTSPClient::startPlayingStreams()
    22-09-2011 20:51:46.204 [1dec]CRTSPClient::clientStartPlayingSession()
    22-09-2011 20:51:46.204 [1dec]CRTSPClient::clientStartPlayingSession() play from 0.000 / 4017.769
    22-09-2011 20:51:46.216 [1dec]Started playing session
    22-09-2011 20:51:46.217 [1dec]CRTSPClient::confused:tartBufferThread
    22-09-2011 20:51:46.217 [1dec]CRTSPClient::confused:tartBufferThread done
    22-09-2011 20:51:46.218 [2674]CRTSPClient:: thread started:9844
    22-09-2011 20:51:48.037 [1dec]demux:endoffile
    22-09-2011 20:51:48.047 [1dec]demux:endoffile
    22-09-2011 20:51:48.057 [1dec]demux:endoffile
    22-09-2011 20:51:48.067 [1dec]demux:endoffile
    2-09-2011 20:51:51.211 [1dec]demux:endoffile
    22-09-2011 20:51:51.221 [1dec]memorybuffer: run:0 1
    22-09-2011 20:51:51.221 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:51.221 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:51.221 [1dec]memorybuffer: running:0
    22-09-2011 20:51:51.222 [1dec]close rtsp:rtsp://media-PC:554/2E39FE57
    22-09-2011 20:51:51.222 [1dec]CRTSPClient:confused:top
    22-09-2011 20:51:51.222 [1dec]CRTSPClient::confused:topBufferThread
    22-09-2011 20:51:51.297 [2674]CRTSPClient:: thread stopped:9844
    22-09-2011 20:51:51.297 [1dec]CRTSPClient::confused:topBufferThread done
    22-09-2011 20:51:51.298 [1dec]CRTSPClient::shutdown()
    22-09-2011 20:51:51.298 [1dec]CRTSPClient::closeMediaSinks()
    22-09-2011 20:51:51.298 [1dec]CMemorySink::dtor
    22-09-2011 20:51:51.298 [1dec]CRTSPClient::tearDownStreams()
    22-09-2011 20:51:51.299 [1dec]CRTSPClient::clientTearDownSession()
    22-09-2011 20:51:51.306 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:51.307 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:51.307 [1dec]CRTSPClient:confused:top done
    22-09-2011 20:51:52.361 [1dec]aud:CompleteConnect()
    22-09-2011 20:51:52.362 [1dec]aud:CompleteConnect() done
    22-09-2011 20:51:52.436 [1dec]CTsReaderFilter::pause() - IsTimeShifting = 0 - state = 0
    22-09-2011 20:51:52.437 [1dec] -- Pause() ->start rtsp from 0.000000
    22-09-2011 20:51:52.437 [1744]aud:OnThreadStartPlay(0.000000) 1.00
    22-09-2011 20:51:52.437 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:52.437 [1744]aud:set eof
    22-09-2011 20:51:52.438 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:52.438 [1dec]demux:flushing
    22-09-2011 20:51:52.438 [1dec]demux:set hold audio:1
    22-09-2011 20:51:52.438 [1dec]demux:set hold video:1
    22-09-2011 20:51:52.439 [1dec]demux:set hold subtitle:1
    22-09-2011 20:51:52.439 [1dec]demux:flush audio
    22-09-2011 20:51:52.439 [1dec]demux:flush video
    22-09-2011 20:51:52.439 [1dec]demux:flush subtitle
    22-09-2011 20:51:52.439 [1dec]demux:set hold audio:0
    22-09-2011 20:51:52.439 [1dec]demux:set hold video:0
    22-09-2011 20:51:52.440 [1dec]demux:set hold subtitle:0
    22-09-2011 20:51:52.440 [1dec]memorybuffer: run:1 0
    22-09-2011 20:51:52.440 [1dec]memorybuffer: running:1
    22-09-2011 20:51:52.440 [1dec]CRTSPClient::play from 0.000000 / 0.000000
    22-09-2011 20:51:52.440 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:52.440 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:52.441 [1dec]CRTSPClient::Initialize()
    22-09-2011 20:51:52.441 [1dec]CRTSPClient::createClient()
    22-09-2011 20:51:52.441 [1dec]CRTSPClient::OpenStream()
    22-09-2011 20:51:52.441 [1dec]CRTSPClient::getSDPDescriptionFromURL()
    22-09-2011 20:51:52.465 [1dec]rangestart:0.000000 rangeend:4017.769000
    22-09-2011 20:51:52.466 [1dec]Created receiver for video MP2T 50192 50193
    22-09-2011 20:51:52.466 [1dec]rtsp:increaseReceiveBufferTo to 2000000 for s:2192
    22-09-2011 20:51:52.466 [1dec]CRTSPClient::setupStreams()
    22-09-2011 20:51:52.466 [1dec]CRTSPClient::clientSetupSubsession()
    22-09-2011 20:51:52.470 [1dec]Setup video MP2T 50192 50193
    22-09-2011 20:51:52.471 [1dec]CMemorySink::ctor
    22-09-2011 20:51:52.471 [1dec]Created output sink:
    22-09-2011 20:51:52.471 [1dec]CRTSPClient::startPlayingStreams()
    22-09-2011 20:51:52.471 [1dec]CRTSPClient::clientStartPlayingSession()
    22-09-2011 20:51:52.471 [1dec]CRTSPClient::clientStartPlayingSession() play from 0.000 / 4017.769
    22-09-2011 20:51:52.474 [1dec]Started playing session
    22-09-2011 20:51:52.475 [1dec]CRTSPClient::confused:tartBufferThread
    22-09-2011 20:51:52.475 [1dec]CRTSPClient::confused:tartBufferThread done
    22-09-2011 20:51:52.476 [1dec] -- Pause() ->rtsp started
    22-09-2011 20:51:52.476 [1dec]Timeshift 0, Recording 1, StartPCR 0.000000, EndPcr 4017.769000, Duration 4017.768000
    22-09-2011 20:51:52.476 [1ccc]CRTSPClient:: thread started:7372
    22-09-2011 20:51:52.476 [1dec]CTsReaderFilter::pause() - END - state = 1
    22-09-2011 20:51:52.477 [219c]CTsReaderFilter::ThreadProc start()
    22-09-2011 20:51:52.477 [219c]CTsReaderFilter::ThreadProc stopped()
    22-09-2011 20:51:52.478 [1dec]filt:IID_IMediaSeeking()
    22-09-2011 20:51:52.478 [1dec]CTsReaderFilter::Run(251921.58) state 1 seeking 0
    22-09-2011 20:51:52.478 [1dec]CTsReaderFilter::Run(251921.58) state 2 -->done
    22-09-2011 20:51:52.492 [1dec]SetAudioStream : 0
    22-09-2011 20:51:52.495 [1dec]SetAudioStream : 0
    22-09-2011 20:51:52.586 [1dec]CTsReaderFilter::pause() - IsTimeShifting = 0 - state = 2
    22-09-2011 20:51:52.587 [1dec] -- Pause() ->pause rtsp at position: 783402.034000
    22-09-2011 20:51:52.587 [1dec]CRTSPClient::pause()
    22-09-2011 20:51:52.587 [1dec]CRTSPClient::pause() stopthread
    22-09-2011 20:51:57.554 [1ccc]CRTSPClient:: thread stopped:7372
    22-09-2011 20:51:57.554 [1dec]CRTSPClient::pause() thread stopped
    22-09-2011 20:51:57.557 [1dec]CRTSPClient::pause() done
    22-09-2011 20:51:57.557 [1dec]CTsReaderFilter::pause() - END - state = 1
    22-09-2011 20:51:57.558 [2164]CTsReaderFilter::ThreadProc start()
    22-09-2011 20:51:57.558 [2164]CTsReaderFilter::ThreadProc stopped()
    22-09-2011 20:51:57.563 [1dec]CTsReaderFilter::confused:top()
    22-09-2011 20:51:57.563 [1dec]CTsReaderFilter::confused:top() -stop source
    22-09-2011 20:51:57.564 [1dec]CTsReaderFilter::confused:top() -stop source done
    22-09-2011 20:51:57.564 [1dec]CTsReaderFilter::confused:top() -- stop rtsp
    22-09-2011 20:51:57.564 [1dec]memorybuffer: run:0 1
    22-09-2011 20:51:57.565 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:57.565 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:57.565 [1dec]memorybuffer: running:0
    22-09-2011 20:51:57.566 [1dec]CRTSPClient:confused:top
    22-09-2011 20:51:57.566 [1dec]CRTSPClient::shutdown()
    22-09-2011 20:51:57.566 [1dec]CRTSPClient::closeMediaSinks()
    22-09-2011 20:51:57.567 [1dec]CMemorySink::dtor
    22-09-2011 20:51:57.567 [1dec]CRTSPClient::tearDownStreams()
    22-09-2011 20:51:57.567 [1dec]CRTSPClient::clientTearDownSession()
    22-09-2011 20:51:57.576 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:57.576 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:57.576 [1dec]CRTSPClient:confused:top done
    22-09-2011 20:51:57.577 [1dec]CTsReaderFilter::confused:top() done
    22-09-2011 20:51:58.127 [1dec]CTsReaderFilter::dtor
    22-09-2011 20:51:58.127 [1dec]pin:dtor()
    22-09-2011 20:51:58.127 [1dec]sub pin:dtor()
    22-09-2011 20:51:58.128 [1dec]FileReader::CloseFile() no open file
    22-09-2011 20:51:58.128 [1dec]CMemoryBuffer::dtor
    22-09-2011 20:51:58.128 [1dec]memorybuffer: Clear() 0
    22-09-2011 20:51:58.128 [1dec]memorybuffer: Clear() done
    22-09-2011 20:51:58.129 [1dec]CRTSPClient::~CRTSPClient()
    22-09-2011 20:51:58.129 [1dec]demux:flushing
    22-09-2011 20:51:58.129 [1dec]demux:set hold audio:1
    22-09-2011 20:51:58.130 [1dec]demux:set hold video:1
    22-09-2011 20:51:58.130 [1dec]demux:set hold subtitle:1
    22-09-2011 20:51:58.130 [1dec]demux:flush audio
    22-09-2011 20:51:58.130 [1dec]demux:flush video
    22-09-2011 20:51:58.131 [1dec]demux:flush subtitle
    22-09-2011 20:51:58.131 [1dec]demux:set hold audio:0
    22-09-2011 20:51:58.131 [1dec]demux:set hold video:0
    22-09-2011 20:51:58.131 [1dec]demux:set hold subtitle:0
    sincze, September 22, 2011
    Share #3

  4. glenn 1990 Portal Pro

    System Specs
    Can this be added to the trunk??

    This is the only way to get rtsp working with my powerlan (low bandwidth) client.
    Now the powerlan adapters are getting more popular, more people will face against this problem.
    glenn 1990, October 13, 2011
    Share #4
    • Team MediaPortal

    Owlsroost Development Group

    System Specs
    I'll build a version of the 1.2.1 TsReader.ax soon with the patch included so people can test it.

    Tony
    Owlsroost, October 13, 2011
    Share #5
    • Like Like x 2

  6. sincze Portal Pro

    Great. Put me on your beta-testers list. ;-0
    Still my wireless connection speed is 100 mbit, the other machine is connected wired to my ubee router at 1 gigabit.
    sincze, October 13, 2011
    Share #6
    • Team MediaPortal

    Owlsroost Development Group

    System Specs
    OK, here it is :)

    Because it's easier for me, it also includes the 'graph rebuild on zapping' mod which has been around for a while.

    I can't easily test the RTSP stuff, so it's in your hands.... ;)

    EDIT: Binary removed - see http://forum.team-mediaportal.com/submit-code-patches-mediaportal-tv-server-etc-325/slow-rtsp-startup-causes-eof-indication-96460/index2.html#post801539

    Tony
    Owlsroost, October 13, 2011
    Share #7
    • Premium Supporter

    pilehave Community Skin Designer

    Would graph rebuild on zapping do anything for those that do not use RTSP?
    pilehave, October 14, 2011
    Share #8
    • Team MediaPortal

    Owlsroost Development Group

    System Specs
    Yes, mostly in situations where the video frame size changes but the video/audio type doesn't - some video codecs break in this situation. The mod has been around in various test versions for a while, but it was too late to include it in 1.2.0 - it's likely to go into 1.2.2

    Tony
    Owlsroost, October 14, 2011
    Share #9
    • Like Like x 1
    • Premium Supporter

    disaster123 MP Donator

    AW: Slow RTSP startup causes EOF indication

    @Owlroost
    i can't finde that patch (graph rebuild) in the patch submission forum?
    disaster123, October 14, 2011
    Share #10
Page 1 of 3

Share This Page

Users Viewing Thread (Users: 0, Guests: 0)

Running the latest version?

V1.3.0 FINAL - released March 2013
Releasenews | Download
Changelog | Requirements
MediaPortal Media Center

Features | Screenshots
Documentation
MediaPortal Bugtracker
MediaPortal RSS Feeds

windows media center News & Blogs
htpc P&S: New
htpc Documentation
htpc Forum
htpc P&S: Updated
htpc Bugtracker
HTPC
Team-MediaPortal
 
About
Contact |  Press
Partners