Locked time-shift files cause failure to change channel (1 Viewer)

Charlie TV

MP Donator
  • Premium Supporter
  • February 22, 2014
    81
    27
    Home Country
    United Kingdom United Kingdom
    Apologise on the terminology. I got the same can't stream issue and have to stop the TV service and restart it, seems to be some kind of file lock issue? MP is left on continuous and I had just turned on the TV and was trying to watch bbc3 I captured the server logs within a couple of minutes of this issue so around 19:30.

    Cheers
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Okay.

    I'm quite confident this problem has nothing to do with the LIVE555 update because I didn't change any file handling. So, while I'm thankful for your report and happy to try to assist you with the problem, I'd prefer to do it in a separate thread.

    Either way, log files alone aren't going to enable me to figure out what the problem is. In addition to the log files I need:
    1. A full list of files - name, size, creation date/time, modification date/time - on the RAM disk at the time the problem occurs. Restarting the TV service will cause some or all time-shifting files to be deleted. After that happens it's impossible for me to see what could have been causing the problem.
    2. The list of processes which are using/locking each file [at the time the problem occurs]. You can use Resource Monitor to get this information.
     

    Charlie TV

    MP Donator
  • Premium Supporter
  • February 22, 2014
    81
    27
    Home Country
    United Kingdom United Kingdom
    Sure no worries mate. Let me upgrade everything from 1.12 to 1.13 and I'll try and capture logs and file information as requested and post in a new thread :)

    Cheers
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Thanks. :)
    I can move all the existing posts about this problem into a new thread, so don't worry about starting a new thread yourself.
     

    Charlie TV

    MP Donator
  • Premium Supporter
  • February 22, 2014
    81
    27
    Home Country
    United Kingdom United Kingdom
    Hi

    So the client screen was frozen at 04:23.

    I've taken logs from the client and server, plus various screenshots. Interestingly the server is showing its timeshifting to the client but the client has a frozen screen. Plus the server is running at 25% cpu which is high, when I stop the tvservice and restart the CPU is a lot lower 1%.

    Let me know anything you want me to try out, (note I'm only using one client at the moment)

    Cheers
     

    Attachments

    • Image2.jpg
      Image2.jpg
      176.8 KB
    • Image3.jpg
      Image3.jpg
      169.2 KB
    • Image4.jpg
      Image4.jpg
      85.5 KB
    • Image5.jpg
      Image5.jpg
      210.2 KB
    • Image6.jpg
      Image6.jpg
      201.4 KB

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Thanks for your persistence Charlie TV - the information you've provided is excellent (y)
    I've spent the last hour or so looking at logs, screenshots and code but haven't yet been able to formulate a cohesive explanation. More investigation will be required. Right now it's 1:30 AM here in NZ so I need to get to bed. I'll try to find more time to look at this tomorrow.
    Thanks again.
     

    Owlsroost

    Retired Team Member
  • Premium Supporter
  • October 28, 2008
    5,540
    5,038
    Cambridge
    Home Country
    United Kingdom United Kingdom
    Charlie TV:

    Under normal circumstances how often does this problem happen ?

    When you say 'MP is left on continuous' do you mean that live TV is playing in MP continuously and you just turn the display(TV) off, or do you stop live TV in MP before turning off the display(TV) ?

    I'm just trying to get an idea of the sequence of events leading up to the problem...
     

    Charlie TV

    MP Donator
  • Premium Supporter
  • February 22, 2014
    81
    27
    Home Country
    United Kingdom United Kingdom
    Hi, it varies but is pretty regular. Sometimes daily, sometimes every few days, possibly depending whether I leave it on a HD or a SD channel. I can cause it to happen faster if I have multiple clients pulling from the server. Yep I just leave MP running particularly on a HD channel and turn off the TV, so when I turn the TV back on I notice its frozen. However its not related to turning the tv off or on, as the frozen state is a number of hours later.

    Hope that helps
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    @Owlsroost
    A brief outline of what I've been thinking...

    The thing that stands out to me first is the streaming server suddenly starting to fail to calculate the stream duration properly:
    26-01-2016 04:14:03.364 generateSDPDescription() duration 4514.054199 : a=range:npt=0-4514.054
    26-01-2016 04:14:09.869 generateSDPDescription() duration 0.000000 : a=range:npt=0-

    If you adjust for the clock difference between client and server (~1m 11s) that timing seems to coincide nicely with the TsReader duration requests starting to time out:
    [2016-01-26 04:12:57,652] [1a00eaf0] [ ba4] - CRTSPClient::UpdateDuration(): RTSP DESCRIBE timed out, message = liveMedia6
    [2016-01-26 04:13:01,375] [1a00eaf0] [ ba8] - CRTSPClient::ThreadProc(): recreate RTSP client

    So, I assume these events are connected in some way. However a zero-value duration would not be directly interpreted as a time-out. Time-out is independent:
    https://github.com/MediaPortal/Medi...owFilters/TsReader/source/RTSPClient.cpp#L522

    Therefore I'm left uncertain as to exactly what the connection is.


    I suspect the CPU usage on the server side is TsWriter spinning its wheels trying to create/reuse files, and all the logging. This seems to start some time after the streaming server duration calculation failure:
    [2016-01-26 04:32:49,964] [48ca9b0] [1b24] - MultiFileWriter: failed to create file E:\\live9-0.ts.tsbuffer5.ts
    [2016-01-26 04:32:49,964] [48ca9b0] [1b24] - Failed to reopen old file. It's currently in use. Dropping data!

    Based on the ~10 minute gap between creation timestamps on the time-shift files (as shown in the screenshots), I'm wondering if the delay between the streaming server and TsWriter problems starting could coincide with the time it takes TsWriter to fill a single time-shift buffer file. If it did, I was thinking maybe the failure in streaming server was responsible for locking the buffer file, thereby triggering the TsWriter problems. However the delay is a little bit on the long side so I'm uncertain...


    Currently my thinking is that the frozen screen on the client side is just a delayed symptom of the streaming server and/or TsWriter problems. The thing that doesn't make sense to me is the delay. From the continuity errors in the TsReader log I assume that TsReader is receiving data (and codecs are decoding/displaying, and renderers are rendering) until ~4:22. That's smack bang between the streaming server and TsWriter problem start times. I can't figure out why it should be that time, and not at the same time as either streaming server or TsWriter falling over. I did note with some interest during my LIVE555 update testing that TsReader seems to be able to continue playing an RTSP stream even without duration updates. On that basis I'm assuming it's more likely to be the TsWriter issue that directly causes TsReader to stop receiving data (=> freeze). However perhaps streaming server's failure to calculate durations is a symptom of a wider problem that eventually causes it to stop streaming completely.

    Lots of uncertainties... ;)
     

    Charlie TV

    MP Donator
  • Premium Supporter
  • February 22, 2014
    81
    27
    Home Country
    United Kingdom United Kingdom
    Howdy,

    I've been away on holiday so not had the time to investigate but have now synced the clocks on the server and client.

    Attached logs are from the latest freeze, interestingly the client was frozen with 02:25 shown on the news ticker tape clock, whereas the buffer screenshot shows times which are from two hours earlier. :s

    Hope it helps

    Cheers
     

    Attachments

    • TVSERVER.jpg
      TVSERVER.jpg
      112 KB

    Users who are viewing this thread

    Top Bottom