TSWriter deadlock potential fix. (1 Viewer)

doskabouter

Development Group
  • Team MediaPortal
  • September 27, 2009
    4,621
    3,031
    Nuenen
    Home Country
    Netherlands Netherlands
    I'm still having issues every couple of months (3 perhaps 4?). If there's an update for 1.2.3 I'll be able to test.
    Although you won't get fast results as it happens not very often...
     

    ramu

    Portal Pro
    July 15, 2008
    190
    7
    Hi DJBue,

    please, tell me that You and Your team is still working on this bug. It's frustating to restart MP every day...

    ramu
     

    ramu

    Portal Pro
    July 15, 2008
    190
    7
    HI,

    whats up with the 1.3.0 final, did anything of this patches out of the thread the way into 1.3.0 final? Or is it a god idea to use these patches also for 1.3.0?

    Who can we support this work to get a thread-safe MP?

    Yours
    ramu
     

    esas

    Portal Pro
    November 14, 2006
    160
    27
    Home Country
    Norway Norway
    My Tv-Server usually crashes once a month or so. Been running v13 of this fix for the last two weeks, and haven't seen anything negative yet. I don't know if this fix solves my problem, but it doesn't seem to introduce any other problems.

    Is this ready for 1.4.0?
     

    elliottmc

    Retired Team Member
  • Premium Supporter
  • August 7, 2005
    14,927
    6,061
    Cardiff, UK
    Home Country
    United Kingdom United Kingdom
    My Tv-Server usually crashes once a month or so. Been running v13 of this fix for the last two weeks, and haven't seen anything negative yet. I don't know if this fix solves my problem, but it doesn't seem to introduce any other problems.

    Is this ready for 1.4.0?

    @DJBlu - it's a good question. How do you feel about this for 1.4.0 ?
     

    infinite.loop

    Retired Team Member
  • Premium Supporter
  • December 26, 2004
    16,163
    4,133
    127.0.0.1
    Home Country
    Austria Austria
    My Tv-Server usually crashes once a month or so. Been running v13 of this fix for the last two weeks, and haven't seen anything negative yet. I don't know if this fix solves my problem, but it doesn't seem to introduce any other problems.

    Is this ready for 1.4.0?

    @DJBlu - it's a good question. How do you feel about this for 1.4.0 ?
    +1

    would be nice to know the status of this here. :)
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    @DJBlu
    Looks like you've made some excellent progress with this issue.
    Having said that, personally I don't understand how your changes are solving the problem.
    Are you able to explain a little?

    My perspective is this...
    The deadlock at GetNewSubChannel() (which is calling CMpTs::AddChannel()) is obviously blocking on the m_Lock declared in CMpTs.
    We can see who/what is holding the lock by reading/comparing logs very carefully. I've attached such a sample with the epg.log, tv.log and TsWriter.log stitched together. Compare the output of the last successful EPG grab (for "ANTENA 3"):

    2013-05-14 16:28:01.322053 [EPG Update thread(21)]: EpgGrabbing: Stop - user epg

    2013-05-14 16:28:01.357058 [EPG Update thread(21)]: user:epg remove
    2013-05-14 16:28:01.422066 [EPG Update thread(21)]: tvcard:FreeSubChannel: subchannels count 1 subch#0
    2013-05-14 16:28:01.486074 [EPG Update thread(21)]: DVB subch:0 Decompose()

    14-05-2013 16:28:01.518 del m_pVideoAnalyzer
    14-05-2013 16:28:01.522 analyzer: reset
    14-05-2013 16:28:01.526 del m_pPmtGrabber
    14-05-2013 16:28:01.529 del m_pRecorder
    14-05-2013 16:28:01.533 del m_pTimeShifting
    14-05-2013 16:28:01.536 del m_pTeletextGrabber
    14-05-2013 16:28:01.540 del m_pCaGrabber
    14-05-2013 16:28:01.543 del done...

    2013-05-14 16:28:01.550087 [EPG Update thread(21)]: FreeSubChannel CA: freeing sub channel : 0
    2013-05-14 16:28:01.614090 [EPG Update thread(21)]: tvcard:FreeSubChannel : no subchannels present, pausing graph
    2013-05-14 16:28:01.677098 [EPG Update thread(21)]: dvb:confused:topGraph called
    2013-05-14 16:28:01.743107 [EPG Update thread(21)]: tvcard:FreeAllSubChannels
    2013-05-14 16:28:01.807115 [EPG Update thread(21)]: dvb:confused:topGraph

    14-05-2013 16:28:01.838 CMpTsFilter::pause()
    14-05-2013 16:28:01.842 CMpTsFilter::confused:top()

    2013-05-14 16:28:02.085151 [EPG Update thread(21)]: Pausecard
    2013-05-14 16:28:02.150159 [EPG Update thread(21)]: dvb:confused:topGraph called
    2013-05-14 16:28:02.215167 [EPG Update thread(21)]: tvcard:FreeAllSubChannels
    2013-05-14 16:28:02.279175 [EPG Update thread(21)]: dvb:confused:topGraph filterstate already stopped, returning.

    2013-05-14 16:28:15.729892 [DVB EPG timer(13)]: Grab for card:#10 transponder #7/12 channel: Canal Catala Barcelona
    2013-05-14 16:28:15.741886 [DVB EPG timer(13)]: EpgCard: grab epg on card: #10 transponder: #6 ch:Canal Catala Barcelona

    ...with the failure:

    2013-05-14 16:29:20.132070 [(18)]: EpgGrabbing: Stop - user epg

    2013-05-14 16:29:20.136070 [(18)]: user:epg remove
    2013-05-14 16:29:20.169074 [(18)]: tvcard:FreeSubChannel: subchannels count 1 subch#0
    2013-05-14 16:29:20.200078 [(18)]: DVB subch:0 Decompose()

    14-05-2013 16:29:20.232 del m_pVideoAnalyzer
    14-05-2013 16:29:20.236 analyzer: reset
    14-05-2013 16:29:20.239 del m_pPmtGrabber
    14-05-2013 16:29:20.243 del m_pRecorder
    14-05-2013 16:29:20.246 del m_pTimeShifting
    14-05-2013 16:29:20.250 del m_pTeletextGrabber
    14-05-2013 16:29:20.253 del m_pCaGrabber
    14-05-2013 16:29:20.257 del done...

    2013-05-14 16:29:20.261086 [(18)]: FreeSubChannel CA: freeing sub channel : 0
    2013-05-14 16:29:20.294090 [(18)]: tvcard:FreeSubChannel : no subchannels present, pausing graph
    2013-05-14 16:29:20.325094 [(18)]: dvb:confused:topGraph called
    2013-05-14 16:29:20.358099 [(18)]: tvcard:FreeAllSubChannels
    2013-05-14 16:29:20.389102 [(18)]: dvb:confused:topGraph

    14-05-2013 16:29:20.421 CMpTsFilter::pause()
    14-05-2013 16:29:20.425 CMpTsFilter::confused:top()

    2013-05-14 16:29:45.773335 [DVB EPG timer(4)]: Grab for card:#10 transponder #8/12 channel: Nitro
    2013-05-14 16:29:45.786331 [DVB EPG timer(4)]: EpgCard: grab epg on card: #10 transponder: #7 ch:Nitro

    Note that thread 18 in the second section is locking in CMpTsFilter::confused:top(). There is no "Pausegraph" entry.
    This is telling me that for some reason the filter is refusing to stop.

    Here's the corresponding function:
    Code:
    STDMETHODIMP CMpTsFilter::Stop()
    {
      CAutoLock cObjectLock(m_pLock);
    	LogDebug("CMpTsFilter::Stop()");
      return CBaseFilter::Stop();
    }

    Quite simple really.
    We can tell that m_pLock is the same lock as is used for CMpTs::AddChannel() by examining the constructor of CMpTs, the constructor of CMpTsFilter and the declaration of CBaseFilter in amfilter.h:
    m_pFilter = new CMpTsFilter(this, GetOwner(), &m_Lock, phr);
    CMpTsFilter::CMpTsFilter(CMpTs *pDump,LPUNKNOWN pUnk,CCritSec *pLock,HRESULT *phr) :
    CBaseFilter(NAME("TsWriter"), pUnk, pLock, CLSID_MpTsFilter),
    m_pWriterFilter(pDump)
    {
    }
    CCritSec *m_pLock; // Object we use for locking
    CBaseFilter(
    __in_opt LPCTSTR pName, // Object description
    __inout_opt LPUNKNOWN pUnk, // IUnknown of delegating object
    __in CCritSec *pLock, // Object who maintains lock
    REFCLSID clsid); // The clsid to be used to serialize this filter


    What I don't understand is why CBaseFilter::confused:top() is blocking.

    Note that the example above is about as single-threaded as TV Server can get. Sequential tunes, over and over again... then we get this.

    mm
     

    Users who are viewing this thread

    Top Bottom