Active recordings not playable

[puenktchen]

@margro @ksooo
Don't know when this started, but right now active recordings are not playable anymore.
One have to wait for the recording to finish, otherwise you get an error "empty url".
This happens with Kodi Jarvis 16.1 and Kodi Krypton nightlies,
MediaPortal TVServer 1.15 and TVServer Kodi plugin 1.15.0.134.

00:38:16 T:143304  NOTICE: VideoPlayer: Opening: pvr://recordings/tv/active/Outcast [1]/Outcast [1] - 10. Wie Kinder ohne Licht s01e10, TV (FOX HD), 20160815_220009, 984.pvr
00:38:16 T:143304 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
00:38:16 T:143304   ERROR: DXVA::CProcessorHD::IsFormatSupported - Unsupported format 104 for 1.
00:38:16 T:143304   ERROR: DXVA::CProcessorHD::IsFormatSupported - Unsupported format 105 for 1.
00:38:16 T:142172  NOTICE: Creating InputStream
00:38:16 T:142172  NOTICE: AddOnLog: MediaPortal PVR Client: OpenRecordedStream (id=984)
00:38:16 T:142172   ERROR: AddOnLog: MediaPortal PVR Client: Recording playback not possible. Backend returned empty filename or stream URL for recording id 984
00:38:16 T:142172   ERROR: CVideoPlayer::OpenInputStream - error opening [pvr://recordings/tv/active/Outcast [1]/Outcast [1] - 10. Wie Kinder ohne Licht s01e10, TV (FOX HD), 20160815_220009, 984.pvr]
00:38:16 T:142172  NOTICE: CVideoPlayer::OnExit()
00:38:16 T:143304  NOTICE: CVideoPlayer::CloseFile()
00:38:16 T:143304  NOTICE: VideoPlayer: waiting for threads to exit
00:38:16 T:143304  NOTICE: VideoPlayer: finished waiting

[margro]

Unfortunately I'm not able to reproduce this. I can play in-progress recordings without problems in Jarvis and Krypton because I'm not seeing the 'empty url' errors.
Somehow on your system, the TVServerKodi backend plugin is not able to return the filename of the recording or the rtsp url. Could you post a TV Server log file with the TVServerKodi response?

[puenktchen]

This is what happens in TVServer's log when trying to play an active recording:

[2016-10-04 02:34:45,473] [Log    ] [PS StandbyWakeup] [DEBUG] - PS: System is busy and should not go to standby
[2016-10-04 02:34:46,518] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetRecordingStopTime
[2016-10-04 02:34:46,852] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace
[2016-10-04 02:34:47,347] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount
[2016-10-04 02:34:47,359] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount
[2016-10-04 02:34:47,363] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount
[2016-10-04 02:34:49,568] [Log    ] [5        ] [DEBUG] - TVServerKodi: Handling command: GetRecordingInfo
[2016-10-04 02:34:49,573] [Log    ] [5        ] [DEBUG] - TVServerKodi: Exception while processing connection: System.IO.IOException: Von der Übertragungsverbindung können keine Daten gelesen werden: Eine vorhandene Verbindung wurde vom Remotehost geschlossen. ---> System.Net.Sockets.SocketException: Eine vorhandene Verbindung wurde vom Remotehost geschlossen
   bei System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   bei System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- Ende der internen Ausnahmestapelüberwachung ---
   bei System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   bei System.IO.StreamReader.ReadBuffer()
   bei System.IO.StreamReader.ReadLine()
   bei TVServerKodi.ConnectionHandler.ProcessConnection(StreamReader reader)
[2016-10-04 02:34:49,573] [Log    ] [5        ] [DEBUG] - TVServerKodi: Connection closed
[2016-10-04 02:34:49,595] [Log    ] [21       ] [DEBUG] - TVServerKodi: New Connection! Starting handler thread for client.192.168.0.3:27320
[2016-10-04 02:34:49,596] [Log    ] [21       ] [DEBUG] - TVServerKodi: Waiting for clients...
[2016-10-04 02:34:49,600] [Log    ] [31       ] [DEBUG] - TVServerKodi: connection accepted from XBMC PVR addon
[2016-10-04 02:34:49,601] [Log    ] [31       ] [DEBUG] - TVServerKodi: Handling command: GetCardSettings
[2016-10-04 02:34:49,619] [Log    ] [31       ] [DEBUG] - TVServerKodi: Handling command: ListRecordings

The rtsp url that is generated for an active recording is playable in VLC:

[2016-10-04 02:39:44,135] [Log    ] [12       ] [INFO ] - Controller: streaming url:rtsp://192.168.0.3:554/8B8EA422 file:\\192.168.0.3\Aufnahmen\Reservoir Dogs - Wilde Hunde - Reservoir Dogs.ts

[puenktchen]

@margro
If you can't find the root cause of the problem,
can you please create an option in the Kodi addon to use ffmpeg for recordings only, but tsreader still for live tv streams (i don't want to lose timeshifting)? This would fix the problem.

[puenktchen]

Hi @margro
with version 2.4.10 of you addon the issue is still not fixed for me.
Now i get a different error in the Kodi logs:

19:13:22.059 T:50436  NOTICE: VideoPlayer: Opening: pvr://recordings/tv/active/Das%20A-Team%20%5B2%5D s02e03%203.%20Zwei%20Nonnen%20zu%20viel, TV%20(RTL%20NITRO), 20161211_181224, 1538.pvr
19:13:22.059 T:50436 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
19:13:22.059 T:50436   ERROR: DXVA::CProcessorHD::IsFormatSupported: Unsupported format 104 for 1.
19:13:22.059 T:50436   ERROR: DXVA::CProcessorHD::IsFormatSupported: Unsupported format 105 for 1.
19:13:22.062 T:191180  NOTICE: Creating InputStream
19:13:22.063 T:191180  NOTICE: AddOnLog: MediaPortal PVR Client: OpenRecordedStream (id=1538, RTSP=1654173208)
19:13:22.070 T:191180   ERROR: AddOnLog: MediaPortal PVR Client: Recording information has not enough fields. At least 9 fields expected, got only 6 fields.
19:13:22.070 T:191180   ERROR: AddOnLog: MediaPortal PVR Client: Parsing result from 'GetRecordingInfo:1538|False
                                            ' command failed. Result='1538|2016-12-11 19:12:24Z|2016-12-11 19:12:24Z|RTL NITRO|Das A-Team [2]|3. Zwei Nonnen zu viel ; Land: USA ; Jahr: 1983 ; Genre: Actionserie '.
19:13:22.070 T:191180   ERROR: CVideoPlayer::OpenInputStream - error opening [pvr://recordings/tv/active/Das%20A-Team%20%5B2%5D s02e03%203.%20Zwei%20Nonnen%20zu%20viel, TV%20(RTL%20NITRO), 20161211_181224, 1538.pvr]
19:13:22.070 T:191180  NOTICE: CVideoPlayer::OnExit()
19:13:22.075 T:50436  NOTICE: CVideoPlayer::CloseFile()
19:13:22.075 T:50436  NOTICE: VideoPlayer: waiting for threads to exit
19:13:22.075 T:50436  NOTICE: VideoPlayer: finished waiting
19:13:22.075 T:50436  NOTICE: CVideoPlayer::CloseFile()    ```

[puenktchen]

TVServer debug log: http://pastebin.com/raw/Uch2imE3
Kodi debug log: http://pastebin.com/raw/L41sgfze

Haha, i think i've finally found what creates the problem!!! I'm using a modified version of the xmltv import plugin in MP TVServer that doesn't remove linebreaks from the program description. Exactly those recordings where the descriptions have linebreaks (nearly all in my case), are failing when trying to play while they are still recording! Can you fix this please?

Just for your reference, this recording is working because i removed the linebreaks:

00:41:47.319 T:12500  NOTICE: VideoPlayer: Opening: pvr://recordings/tv/active/Criminal%20Minds%20%5B6%5D s06e02%202.%20Unter%20Haien, TV%20(SAT.1), 20161212_234040, 1553.pvr
00:41:47.319 T:12500 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
00:41:47.319 T:12500   ERROR: DXVA::CProcessorHD::IsFormatSupported: Unsupported format 104 for 1.
00:41:47.319 T:12500   ERROR: DXVA::CProcessorHD::IsFormatSupported: Unsupported format 105 for 1.
00:41:47.320 T:15296   DEBUG: Thread VideoPlayer start, auto delete: false
00:41:47.320 T:15296  NOTICE: Creating InputStream
00:41:47.321 T:15296  NOTICE: AddOnLog: MediaPortal PVR Client: OpenRecordedStream (id=1553, RTSP=1448979992)
00:41:47.328 T:15296  NOTICE: AddOnLog: MediaPortal PVR Client: RECORDING: 1553|2016-12-13 00:40:40Z|2016-12-13 00:40:40Z|SAT.1|Criminal Minds [6]|2. Unter Haien ; Land: USA ; Jahr: 2010 ; Genre: Krimiserie Die 19-jährige Kate ist verschwunden. Um das Mädchen lebend zu finden, müssen die Profiler JJ (A.J. Cook) und Hotch (Thomas Gibson) zwei Hauptverdächtige schnell zum Reden bringen.  Mitwirkende: Joe Mantegna (David Rossi), Paget Brewster (Emily Prentiss), Matthew Gray Gubler (Dr. Spencer Reid), A. J. Cook (Jennifer "JJ" Jareau), Kirsten Vangsness (Penelope Garcia), Thomas Gibson (Aaron "Hotch" Hotchner), Gil Bellows (Jeff Joyce), Michael Welch (Syd Pearson), Shemar Moore (Derek Morgan), Rya Kihlstedt (Patty Joyce), Charles S. Carroll (Regie), Erica Messer (Drehbuch), Greg Johns (Kamera), Charles S. Carroll (Produzent), Gigi Coello-Bannon (Produzent), Randy Huggins (Produzent), Alicia Kirk (Produzent)||\\HTPC\Recordings\SAT.1 - 2016-12-13.ts|2000-01-01 00:00:00Z
00:41:47.329 T:15296   DEBUG: AddOnLog: MediaPortal PVR Client: PatParser:Reset()
00:41:47.329 T:15296  NOTICE: AddOnLog: MediaPortal PVR Client: TsReader open '\\HTPC\Recordings\SAT.1 - 2016-12-13.ts'
00:41:47.335 T:15296   DEBUG: AddOnLog: MediaPortal PVR Client: Found the timeshift buffer at: \\HTPC\Recordings\SAT.1 - 2016-12-13.ts
00:41:47.335 T:15296    INFO: AddOnLog: MediaPortal PVR Client: FileReader::OpenFile() smb://Administrator:Administrator@HTPC/Recordings/SAT.1 - 2016-12-13.ts.
00:41:47.339 T:15296   DEBUG: AddOnLog: MediaPortal PVR Client: MPTV::FileReader::OpenFile: OpenFile(smb://Administrator:Administrator@HTPC/Recordings/SAT.1 - 2016-12-13.ts) succeeded.    ```

[margro]

Ah, that would explain why I could not reproduce it. Will have a look at this. Thanks for this new piece of the puzzle ;-)

[margro]

Should be fixed with plugin v2.4.14 in combination with TVServerKodi build 1.15.0.137

[puenktchen]

Thank you so much for your support!!!
Working great now.