MP1.16 Remote Client Unable to Play: B43534E1 error watching Recorded TV

Discussion in 'watch/edit Videos' started by RonD, May 10, 2017.

  1. RonD
    • Team MediaPortal

    RonD Test Group

    Joined:
    December 20, 2011
    Messages:
    904
    Likes Received:
    119
    Occupation:
    semi-pro slacker
    Location:
    SillyValley CA
    Ratings:
    +275 / 0
    Home Country:
    United States of America United States of America
    With MP1.16, on remote network connected MP-Clients sometimes see “Unable to Play: B43534E1” type error popup when trying to play a RecordedTV over network connection. Close error, play again and it works 2nd try. The stream ID numbers “B43534E1” etc vary. Does not happen 100% of the time and never saw this with MP1.12.

    Attached zip has log files.
    Unable2PlayClient has logs from Client Startup
    Unable2PlayServer has logs from TV Server Startup a few days ago.

    @mm1352000 and @Owlsroost , I 1st saw this with the “MP1.16 released version” of StreamingServer.dll. Also see this with StreamingServer_dll_v1.1.5.zip from the “RecordingFileHandler: Error while deleting” thread. I’m using this for all my testing.

    The Client logs are from 2nd set of tests in TV Server Logs, starting at 10:45 local, I saw similar error at 10:32, but closed Client then restarted Client to be sure I had consistent log files.



    Started tesing at 10:45 AM local, 2 Shows failed then worked 2nd try
    The Ten O'clock News on KTVU Fox 2 - 2017-05-09.ts
    CBS Evening News With Scott Pelley - 2017-05-09.ts

    From client MediaPortal.log

    1st time failed, The Ten O'clock News on KTVU Fox 2
    [2017-05-10 10:44:50,813] [Log ] [MPMain ] [INFO ] - PlayRecording:rtsp://MePoTVS:554/B43534E1 - using rtsp mode:True
    [2017-05-10 10:44:51,501] [Error ] [MPMain ] [ERROR] - TSReaderPlayer: Failed to open file:rtsp://MePoTVS:554/B43534E1 :0x80004005
    2nd time works
    [2017-05-10 10:48:08,412] [Log ] [MPMain ] [INFO ] - PlayRecording:rtsp://MePoTVS:554/B43534E1 - using rtsp mode:True

    Watch next show, 1st time failed, CBS Evening News With Scott Pelley - 2017-05-09.ts
    [2017-05-10 10:48:57,971] [Log ] [MPMain ] [INFO ] - PlayRecording:rtsp://MePoTVS:554/71E234B9 - using rtsp mode:True
    [2017-05-10 10:48:58,506] [Error ] [MPMain ] [ERROR] - TSReaderPlayer: Failed to open file:rtsp://MePoTVS:554/71E234B9 :0x80004005
    2nd time works
    [2017-05-10 10:49:18,210] [Log ] [MPMain ] [INFO ] - PlayRecording:rtsp://MePoTVS:554/71E234B9 - using rtsp mode:True
     

    Attached Files:

    Last edited: May 10, 2017
  2. Google AdSense Guest Advertisement



    to hide all adverts.
  3. mm1352000
    • Team MediaPortal

    mm1352000 Development Group

    Joined:
    September 1, 2008
    Messages:
    21,527
    Likes Received:
    4,738
    Ratings:
    +8,205 / 17
    Home Country:
    New Zealand New Zealand
    Hello again Ron

    These are stream IDs.

    Looking at the log files now, thanks. :)
     
  4. mm1352000
    • Team MediaPortal

    mm1352000 Development Group

    Joined:
    September 1, 2008
    Messages:
    21,527
    Likes Received:
    4,738
    Ratings:
    +8,205 / 17
    Home Country:
    New Zealand New Zealand
    Hmmmm, it looks like the request to open the recording is failing due to this:
    [2017-05-10 10:44:51,499] [16735aa8] [200c] - CRTSPClient::UpdateDuration(): RTSP DESCRIBE timed out, message = liveMedia1

    The allowed time is half a second. Second time around the request takes only 7 milliseconds:
    [2017-05-10 10:48:08,443] [16735aa8] [26f8] - CRTSPClient::ThreadProc(): thread started, thread ID = 9976
    [2017-05-10 10:48:08,450] [16735aa8] [200c] - CRTSPClient::OpenStream(): duration = 3712138

    ...so something is strange there.

    Most tellingly, on the server side, I don't see the streaming server receiving the request at all. The streaming server only seems to receive the second request. So, in my opinion the most likely cause of this problem is one (or more) of:
    • the client is not actually sending the request
    • security software on the client or server is preventing the request from making it to the server
    It should be possible to confirm what's going on by using Wireshark at both ends to capture/dump the received/sent traffic. Would you be able to do that?
     
  5. Owlsroost
    • Team MediaPortal

    Owlsroost Development Group

    Joined:
    October 28, 2008
    Messages:
    5,537
    Likes Received:
    2,829
    Location:
    Cambridge
    Ratings:
    +4,131 / 1
    Home Country:
    United Kingdom United Kingdom
    Show System Specs
    For the later 71E234B9 stream (K:\MePo1\recordings\KPIX-TV\CBS Evening News With Scott Pelley\CBS Evening News With Scott Pelley - 2017-05-09.ts), for the failed start StreamingServer does seem to respond to an UpdateDuration() request, even though it times out at the client:

    (note: it looks like there is about a 9s logging time skew between the client and server)

    The failed start:

    TsReader.log:
    [2017-05-10 10:48:58,006] [1682cad8] [2f64] - CRTSPClient::ThreadProc(): thread started, thread ID = 12132
    [2017-05-10 10:48:58,505] [1682cad8] [200c] - CRTSPClient::UpdateDuration(): RTSP DESCRIBE timed out, message = liveMedia1

    StreamingServer.log:
    [2017-05-10 10:49:08,068] [2cd0] - TsMp2TFSMediaSubsession::duration(), actual: 1927.209961 s, total: 1927.209961 s
    (the reported duration matches the duration when it is successfully started next time, so it's for the correct file)

    The successful start:

    TsReader.log:
    [2017-05-10 10:49:18,245] [1682cad8] [ 9e4] - CRTSPClient::ThreadProc(): thread started, thread ID = 2532
    [2017-05-10 10:49:18,250] [1682cad8] [200c] - CRTSPClient::OpenStream(): duration = 1927210

    StreamingServer.log:
    [2017-05-10 10:49:27,762] [2cd0] - ts:eek:pen K:\MePo1\recordings\KPIX-TV\CBS Evening News With Scott Pelley\CBS Evening News With Scott Pelley - 2017-05-09.ts
    [2017-05-10 10:49:27,762] [2cd0] - CTSBuffer::ctor
    [2017-05-10 10:49:27,763] [2cd0] - ts:ctor:3fbe6d0
     
  6. RonD
    • Team MediaPortal

    RonD Test Group

    Joined:
    December 20, 2011
    Messages:
    904
    Likes Received:
    119
    Occupation:
    semi-pro slacker
    Location:
    SillyValley CA
    Ratings:
    +275 / 0
    Home Country:
    United States of America United States of America
    updated wording to say "stream ID".

    Will look into getting wireshark setup, BUT not obvious how to reproduce this problem on-demand. I thought the key to reproduce was close MP Client, open MP Client, wait a few minutes for TV-Series etc to finish all startup, scanning, etc. Then watch RecordedTV, see 1st fail then work. I tried to reproduce 2 or 3 times later and problem did not show up again. What was weird, the problem 1st happened at 10:32 when I 1st noticed problem, then again at 10:45 with the Client Log files I uploaded.

    I've seen this on 2 or 3 different days since upgrade to MP1.16, never saw this problem with MP1.12, all on same TV-Server, MP-Client systems, and network setup.

    This Client (L3521) is wired 1 Gbps Ethernet through 2 ethernet switches to TV Server, all 1 Gbps Ethernet. I've also seen this problem on 2nd MP-Client that uses 5 GHz Wifi to ethernet switch to TV Server. This is all after closing MP Client, start MP Client, going to RecordedTV, so MP Client and Server have sent a fair amount of network traffic, strange that "open" fails after all that traffic, video streaming then a 2nd "open" fails.
     
  7. mm1352000
    • Team MediaPortal

    mm1352000 Development Group

    Joined:
    September 1, 2008
    Messages:
    21,527
    Likes Received:
    4,738
    Ratings:
    +8,205 / 17
    Home Country:
    New Zealand New Zealand
    Good catch.
    Do you think that 500 ms is an unreasonable time limit for calculating the duration?
    To me it seems generous. I'd have thought that we'd only be in danger of hitting it if an HDD had to spin up on the server side... or something like that. In this case the HDD - if K: is in fact an HDD - should have already been prepared because it was active less than a minute earlier. So I wonder what could be taking so long.
     
  8. RonD
    • Team MediaPortal

    RonD Test Group

    Joined:
    December 20, 2011
    Messages:
    904
    Likes Received:
    119
    Occupation:
    semi-pro slacker
    Location:
    SillyValley CA
    Ratings:
    +275 / 0
    Home Country:
    United States of America United States of America
    drive K: is HDD, 3000 GB WD drive about 600 GB free space. Another HDD drive L: is used for timeshifting, but TV Sever was idle for everything else when I was doing testing.

    TV Server system has EVO850 240GB SSD for Windows C: drive, all MP programs (exe dlls etc) are on SSD, all MP Data and SQL database is also on SSD. SSD is about 50% empty.

    EDIT: Checked my Win-10 power settings, Turn Off Hard Disk = 0 minute (NEVER), full speed ahead
     
    Last edited: May 11, 2017
  9. mm1352000
    • Team MediaPortal

    mm1352000 Development Group

    Joined:
    September 1, 2008
    Messages:
    21,527
    Likes Received:
    4,738
    Ratings:
    +8,205 / 17
    Home Country:
    New Zealand New Zealand
    @Owlsroost
    I'm discovering that the missing duration entry for the first recording in the streaming server log is not necessarily an indication that the server hasn't received a request.

    The streaming server log file shows earlier interactions for both recordings. Those earlier interactions are the reason for the difference in duration logging. For the second recording, the interaction immediately prior to the failed playback attempt was a seek followed by a manual stop, whereas for the first recording it was a playback completion (end of file reached). That difference affects the value of m_iDurationCount which in turn determines whether the duration will be logged before the next playback attempt.

    In my opinion it would be nice to have the duration logged before playback starts (ie. as per the second recording).

    All this is to say that more investigation is required. Wireshark may give us the best picture of what's going on.
     
  10. RonD
    • Team MediaPortal

    RonD Test Group

    Joined:
    December 20, 2011
    Messages:
    904
    Likes Received:
    119
    Occupation:
    semi-pro slacker
    Location:
    SillyValley CA
    Ratings:
    +275 / 0
    Home Country:
    United States of America United States of America
    I have seen 1 other glitch with RecordedTV rtsp streaming. A few times playing a recording starts ok, but if I timeshift +1 minute get past the pre-store, the video exits back to the RecordedTV screen. I can start playing the recording again and everything is normal. I don't have this any of the logs, but will grab the Client/Server log next time I see the problem.
     
  11. Owlsroost
    • Team MediaPortal

    Owlsroost Development Group

    Joined:
    October 28, 2008
    Messages:
    5,537
    Likes Received:
    2,829
    Location:
    Cambridge
    Ratings:
    +4,131 / 1
    Home Country:
    United Kingdom United Kingdom
    Show System Specs
    I agree.

    It should be fine (provided the HDD is not sleeping) - it basically just reads a very small amount of data from each end of the file to find PCR timestamps, then subtracts start PCR from end PCR.

    It shouldn't do this. There is specific handling in the 'seek' code to make sure it doesn't seek right to - or past - the end of the file (and hence trigger 'end of file' stopping of the stream, which is annoying...). I'll need the client and server logs to work out what might be happening in your case.

    Is this a finished recording, or one in-progress i.e. a 'live' recording?
     
Loading...

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

  1. This site uses cookies to help personalise content, tailor your experience and to keep you logged in if you register.
    By continuing to use this site, you are consenting to our use of cookies.
    Dismiss Notice
  • About The Project

    The vision of the MediaPortal project is to create a free open source media centre application, which supports all advanced media centre functions, and is accessible to all Windows users.

    In reaching this goal we are working every day to make sure our software is one of the best.

             

  • Support MediaPortal!

    The team works very hard to make sure the community is running the best HTPC-software. We give away MediaPortal for free but hosting and software is not for us.

    Care to support our work with a few bucks? We'd really appreciate it!