Jump to content


Photo

Recordings Ending Early

Recordings

  • Please log in to reply
6 replies to this topic

#1 jbirmingham40 OFFLINE  

jbirmingham40

    Advanced Member

  • Members
  • 87 posts
  • Local time: 02:52 AM

Posted 11 January 2019 - 11:36 AM

Over the last few days I have noticed my iptv recordings are ending early.  I am trying to track down the root cause.  Would love some help.  Below is an example show that should have recorded for 62 minutes but instead recorded for 43 minutes.

 

Below you can see the show "ScariestNight of My Life" starts recording at 08:00:00 on-time.  You can also see that it is scheduled to record for 62 minutes.  Then you will notice at 08:43:22 the logs show that the Live Stream Ended with no explanation of why.   

 

I am running Emby Server version 3.6.0.83 beta on CentOS.  FWIW, the problems seemed start after upgrading to 3.6.0.84.  I downgraded a day later back to 3.6.0.83 to try and correct the problem but it persists.  The timing of the start of the issue and the upgrade is possibly coincidental. 

 

Full log attached.

 

2019-01-11 07:59:58.303 Info HttpServer: HTTP Response 200 to 192.168.0.1. Time: 5ms. http://192.168.0.1:8...?IsEnabled=true
2019-01-11 08:00:00.000 Info App: Recording timer fired for Scariest Night of My Life.
2019-01-11 08:00:00.001 Info App: Getting media sources for recording from channel 116973 116973
2019-01-11 08:00:00.019 Info App: Getting media sources for recording from channel 47209 47209
2019-01-11 08:00:00.020 Debug App: Ping test result to http://192.168.0.1:8096/system/ping. Success: True
2019-01-11 08:00:00.021 Debug LiveTvMediaSourceProvider: MediaSources: [{"Protocol":"Http","Id":"8026b3076bd522cb196e989a9fc07bfb","Path":"http://vapi.vaders.t...:"VLC/3.0.1"}}]
2019-01-11 08:00:00.021 Info App: Opening live stream for recording from channel 47209 47209
2019-01-11 08:00:00.021 Info App: Opening channel stream from Emby, external channel Id: m3u_c3d6326a5b27706d7111c20a4ad58fa3e6256a24e62fcec40e15475df07c0e10
2019-01-11 08:00:00.021 Info App: Streaming Channel m3u_c3d6326a5b27706d7111c20a4ad58fa3e6256a24e62fcec40e15475df07c0e10
2019-01-11 08:00:00.021 Info App: Live stream 8026b3076bd522cb196e989a9fc07bfb consumer count is now 2
2019-01-11 08:00:00.021 Info MediaSourceManager: Live tv media info probe took 0.0004577 seconds
2019-01-11 08:00:00.021 Info MediaSourceManager: Live stream opened: {"Protocol":"Http","Id":"8026b3076bd522cb196e989a9fc07bfb","Path":"http://127.0.0.1:809...layTitle":"720pH264","NalLengthSize":"0","IsInterlaced":false,"BitRate":8000000,"BitDepth":8,"RefFrames":1,"IsDefault":false,"IsForced":false,"Height":720,"Width":1280,"AverageFrameRate":59.94006,"RealFrameRate":59.94006,"Profile":"High","Type":"Video","AspectRatio":"16:9","Index":-1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"PixelFormat":"yuv420p","Level":41,"IsAnamorphic":false},{"Codec":"aac","TimeBase":"1/90000","CodecTimeBase":"1/48000","DisplayTitle":"AAC stereo","IsInterlaced":false,"ChannelLayout":"stereo","BitRate":123000,"Channels":2,"SampleRate":48000,"IsDefault":false,"IsForced":false,"Profile":"LC","Type":"Audio","Index":-1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Level":0}],"Formats":[],"Bitrate":8123000,"RequiredHttpHeaders":{"User-Agent":"VLC/3.0.1"},"AnalyzeDurationMs":3000}
2019-01-11 08:00:00.021 Info App: Beginning recording. Will record for 61.9996357033333 minutes.
2019-01-11 08:00:00.021 Info App: Writing file to path: /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.074 Debug LibraryMonitor: New file refresher created for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.nfo
2019-01-11 08:00:00.075 Info App: Triggering refresh on /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.075 Info App: Refreshing recording parent /video/Shows/Scariest Night of My Life/Season 1
2019-01-11 08:00:00.075 Info App: Copying recording stream to file /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.190 Info HttpClient: GET http://192.168.0.4/discover.json
2019-01-11 08:00:00.219 Info HttpClient: GET http://192.168.0.4:80/lineup.json
2019-01-11 08:00:00.281 Debug LiveTvMediaSourceProvider: MediaSources: [{"Protocol":"Udp","Id":"native_2e249708a2f1aa2eb761d603d92a2b86_d434e0f1b5e0e36c8960165687992493","Path":"http://192.168.0.4",...ayTitle":"DolbyDigital","IsInterlaced":false,"BitRate":192000,"IsDefault":false,"IsForced":false,"Type":"Audio","Index":-1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false}],"Formats":[],"Bitrate":2192000,"RequiredHttpHeaders":{}}]
2019-01-11 08:00:00.298 Info HttpServer: HTTP GET http://192.168.0.1:8...?IsEnabled=true. UserAgent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36
2019-01-11 08:00:00.301 Info HttpServer: HTTP Response 200 to 192.168.0.1. Time: 3ms. http://192.168.0.1:8...?IsEnabled=true
2019-01-11 08:00:00.601 Info App: Opening live stream for recording from channel 116973 116973
2019-01-11 08:00:00.601 Info App: Opening channel stream from Emby, external channel Id: hdhr_24.4
2019-01-11 08:00:00.601 Info App: Streaming Channel hdhr_24.4
2019-01-11 08:00:00.632 Debug App: Running FFProbeProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.632 Debug App: Running TvdbEpisodeProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.633 Debug App: Running TvdbEpisodeProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.633 Debug App: Running OmdbEpisodeProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.635 Debug App: Running MovieDbEpisodeProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.635 Debug App: MovieDbEpisodeProvider returned no metadata for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.635 Debug App: Running TvdbEpisodeImageProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.636 Debug App: Running TvdbEpisodeImageProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.636 Debug App: Running MovieDbEpisodeImageProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.637 Debug App: Running OmdbImageProvider for /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:00:00.669 Info HttpClient: GET https://private.omdb...oes=true&r=json
2019-01-11 08:00:00.695 Info App: GetChannelStream: channel id: hdhr_24.4. stream id: native_2e249708a2f1aa2eb761d603d92a2b86_d434e0f1b5e0e36c8960165687992493 profile: native
2019-01-11 08:00:00.696 Info App: Opening SharedHttpStream Live stream from http://192.168.0.4:5004/auto/v24.4
2019-01-11 08:00:00.696 Info HttpClient: GET http://192.168.0.4:5004/auto/v24.4
2019-01-11 08:00:00.877 Info HttpClient: GET https://m.media-amaz...@._V1_SX300.jpg
2019-01-11 08:00:01.038 Debug ProviderManager: Saving image to /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken-thumb.jpg
2019-01-11 08:00:01.090 Info HttpClient: Http response 200 from http://192.168.0.4:5004/auto/v24.4 after 394ms. HeadersServer=HDHomeRun/1.0, Connection=close, Cache-Control=no-cache, Pragma=no-cache, transferMode.dlna.org=Streaming, Date=Fri, 11 Jan 2019 14:00:01 GMT
2019-01-11 08:00:01.090 Info App: Beginning SharedHttpStream stream to /home/emby/transcoding-temp/0447e54d62ad407ebffd309c05b2c831.ts
2019-01-11 08:00:01.091 Info App: Live stream opened after 394.7886ms
2019-01-11 08:00:01.091 Info App: Returning mediasource streamId native_2e249708a2f1aa2eb761d603d92a2b86_d434e0f1b5e0e36c8960165687992493, mediaSource.Id native_2e249708a2f1aa2eb761d603d92a2b86_d434e0f1b5e0e36c8960165687992493, mediaSource.LiveStreamId null
2019-01-11 08:00:01.125 Info MediaSourceManager: Live tv media info probe took 0.0342166 seconds
 
.....
 
2019-01-11 08:43:22.301 Info HttpServer: HTTP Response 200 to 192.168.0.1. Time: 3ms. http://192.168.0.1:8...?IsEnabled=true
2019-01-11 08:43:22.764 Info App: Live Stream ended.
2019-01-11 08:43:22.764 Info App: Recording completed to file /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:43:22.764 Info App: Recording completed: /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
2019-01-11 08:43:22.764 Info MediaSourceManager: Live stream 8026b3076bd522cb196e989a9fc07bfb consumer count is now 0
2019-01-11 08:43:22.764 Info MediaSourceManager: Closing live stream 06044cf0e6f93cdae5f285c9ecfaaeb4_01413a525b3a9622ce6fdf19f7dde354_8026b3076bd522cb196e989a9fc07bfb
2019-01-11 08:43:22.764 Info App: Closing SharedHttpStream
2019-01-11 08:43:22.764 Info MediaSourceManager: Live stream 06044cf0e6f93cdae5f285c9ecfaaeb4_01413a525b3a9622ce6fdf19f7dde354_8026b3076bd522cb196e989a9fc07bfb closed successfully
2019-01-11 08:43:22.765 Info App: Triggering refresh on /video/Shows/Scariest Night of My Life/Season 1/Scariest Night of My Life S01E02 Devil of a Deal and Awoken.ts
 
 
 

Attached Files


Edited by jbirmingham40, 11 January 2019 - 11:37 AM.


#2 Luke OFFLINE  

Luke

    System Architect

  • Administrators
  • 142291 posts
  • Local time: 03:52 AM

Posted 11 January 2019 - 02:14 PM

Hi, did you possibly have a loss of signal on the hdhr?

#3 jbirmingham40 OFFLINE  

jbirmingham40

    Advanced Member

  • Members
  • 87 posts
  • Local time: 02:52 AM

Posted 11 January 2019 - 02:16 PM

It is an iptv stream.  I would certainly not want to rule out the iptv provider being the cause especially since I have experienced issues in the past.  Are there any additional diagnostics I can enable to help rule this in or out?


Edited by jbirmingham40, 11 January 2019 - 02:28 PM.


#4 Luke OFFLINE  

Luke

    System Architect

  • Administrators
  • 142291 posts
  • Local time: 03:52 AM

Posted 12 January 2019 - 01:21 PM

Are you able to play the channel for long periods of time?

#5 jbirmingham40 OFFLINE  

jbirmingham40

    Advanced Member

  • Members
  • 87 posts
  • Local time: 02:52 AM

Posted 14 January 2019 - 10:51 AM

Hard to say.  I don't know how long I would have to watch a particular channel before I could say that this was or was not a problem.  The issue seems to have gone away for the time being.  I therefore suspect it was an issue with my iptv provider.  Would be helpful if there was something in the log however that could indicate when the stream provider exited prematurely to help me narrow down the cause.



#6 Luke OFFLINE  

Luke

    System Architect

  • Administrators
  • 142291 posts
  • Local time: 03:52 AM

Posted 14 January 2019 - 03:36 PM

Thanks for the feedback. Yes i think some alerts about this would make sense.


  • maegibbons likes this

#7 maegibbons OFFLINE  

maegibbons

    Advanced Member

  • Members
  • 2337 posts
  • Local time: 08:52 AM
  • LocationLutterworth, England, UK

Posted 14 January 2019 - 07:35 PM

Anything to help analyse and MONITOR failed IPTV recordings would be very welcome.

 

Plus a retry on a -1, or -2 filename for recordings that have ended prior to schedule.

 

Krs

 

Mark


  • Spaceboy likes this





Also tagged with one or more of these keywords: Recordings

0 user(s) are reading this topic

0 members, 0 guests, 0 anonymous users