MP1.16 Remote Client Unable to Play: B43534E1 error watching Recorded TV (1 Viewer)

RonD

Test Group
  • Team MediaPortal
  • December 20, 2011
    904
    275
    SillyValley CA
    United States of America United States of America
    Country flag
    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
     

    Attachments

    Last edited:

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    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?
     

    Owlsroost

    Development Group
  • Team MediaPortal
  • October 28, 2008
    5,539
    5,037
    Cambridge
    United Kingdom United Kingdom
    Country flag
    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
     

    RonD

    Test Group
  • Team MediaPortal
  • December 20, 2011
    904
    275
    SillyValley CA
    United States of America United States of America
    Country flag
    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.
     

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    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
    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.
     

    RonD

    Test Group
  • Team MediaPortal
  • December 20, 2011
    904
    275
    SillyValley CA
    United States of America United States of America
    Country flag
    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:

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    @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.
     

    RonD

    Test Group
  • Team MediaPortal
  • December 20, 2011
    904
    275
    SillyValley CA
    United States of America United States of America
    Country flag
    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.
     

    Owlsroost

    Development Group
  • Team MediaPortal
  • October 28, 2008
    5,539
    5,037
    Cambridge
    United Kingdom United Kingdom
    Country flag
    All this is to say that more investigation is required. Wireshark may give us the best picture of what's going on.
    I agree.

    Do you think that 500 ms is an unreasonable time limit for calculating the duration?
    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.

    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.
    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?
     

    Users Who Are Viewing This Thread (Users: 0, Guests: 1)

    OP Similar threads Forum Replies Date
    R Problem with MP1 and WifiRemote Skins and Plugins Installer (MPEI) 8
    H MP 1.21 Volume OSD for 1039 MCE remote and MCE keyboard not working 1.21 74
    ajs MP2Web - MP1 compatibility MediaPortal 1 20
    T MadVR + LAV Filters, Perfect in MPC-BE, Bad in MP1 MediaPortal 1 Talk 12
    P MP2: US user, OTA - can NOT get SchedulesDirect plugin to work on MP1 or MP2 --> how do I get OTA schedule? General 5
    framug [solved] Some changes/fix in MP1 configuration client and server Submit: code patches (MediaPortal/TV-Server/etc.) 14
    S TV-Server MP1 - Automatic search doesn't work Installation, configuration support 2
    C Streaming/transcoding MP2 vs MP1? General 1
    ajs [fixed] 5015: Improving the MP1 installer, providing nicer GUI :) MediaPortal 1 138
    C Streaming to clients over Wifi. MP1 or MP2? Newcomers Forum 0
    S Shortcuts MP1 My Recorded & TV Guide General 10
    azzuro [WiP] MP1-4999 - Big changes with many related change at once by Sebastiii MediaPortal 1 12
    ajs [Help Us!] MP1 X64 Version MediaPortal 1 20
    joecrow How about a Launcher plugin for MP1? MediaPortal 1 6
    wizard123 [solved] MP1 Build help MediaPortal 1 21
    ajs [News] MediaPortal 1 - 1.24 Released! News and Announcements 3
    CyberSimian [fixed] MP1-4990 : Improve horizontal scrolling in the EPG MediaPortal 1 10
    azzuro [WiP] MP1-5019: Replace MySQL with MariaDB MediaPortal 1 40
    catalpa Umsteiger von MP1: Schwierigkeiten Allgemeines Support- und Diskussionsforum 17
    CyberSimian [solved] MP1-4976 Built-in skin variables for current date MediaPortal 1 8
    rbo [solved] Umsteiger MP1 zu MP2 Allgemeines Support- und Diskussionsforum 67
    azzuro [Info] MP2 TVE inside MP1 repo MediaPortal 2 12
    G MP1 TV Server "failed to upgrade the database" using MS Sql Server Installation, configuration support 3
    lisag Can I get MP1 to open in the Recorded TV screen? MediaPortal 1 Talk 2
    M MP1 stops responding after Starting Plugins General Support 14
    Similar threads

























    Top Bottom