search

kodi-pvr / pvr.vuplus

Kodi's Enigma2 client add-on
GNU General Public License v2.0
56 stars 55 forks source link

Playback interrupted sometimes after epg query #158

Closed sidey79 closed 5 years ago

sidey79 commented 5 years ago

I've getting freezes (buffer empty) since a while.

I'm not sure if this is a KODI or an addon problem. But what i see very often in the logfile is a timeout waiting for buffer after epg refresh of a channel. And sometimes the video stops and starts buffering again.

Most of the time, it occures two times within an minute.

Her are some log entrys when this occures:

14:52:24.313 T:3576689520   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'PHOENIX HD'
14:52:24.313 T:3576689520    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://xxx:xxx@et9x00:80/web/epgservice?sRef=1%3A0%3A19%3A285B%3A401%3A1%3AC00000%3A0%3A0%3A0%3A'
14:52:24.313 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:20869 dts:4537.579 pts:4537.699 dur:40.000ms, clock:4529.083 level:105
14:52:24.314 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:73065 dts:4537.619 pts:4537.619 dur:40.000ms, clock:4529.083 level:105
14:52:24.315 T:3576689520   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
14:52:24.316 T:3576689520   DEBUG: CurlFile::Open(0x2ee5ae8) http://et9x00:80/web/epgservice?sRef=1%3A0%3A19%3A285B%3A401%3A1%3AC00000%3A0%3A0%3A0%3A
14:52:24.320 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:9134 dts:4537.659 pts:4537.659 dur:40.000ms, clock:4529.083 level:105
14:52:24.775 T:3488584560 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
14:52:24.775 T:3488584560   DEBUG: CVideoPlayerVideo::OutputPicture - ttd:575ms pts:4529.659 Clock:4529.083 Level:-1 elapsed:499.813ms
14:52:25.275 T:3488584560 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
14:52:25.275 T:3488584560   DEBUG: CVideoPlayerVideo::OutputPicture - ttd:595ms pts:4529.679 Clock:4529.083 Level:-1 elapsed:499.797ms
14:52:25.775 T:3488584560 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
14:52:25.775 T:3488584560   DEBUG: CVideoPlayerVideo::OutputPicture - ttd:615ms pts:4529.699 Clock:4529.083 Level:-1 elapsed:499.855ms
14:52:26.169 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:7774 dts:4537.699 pts:4537.739 dur:40.000ms, clock:4529.083 level:106
14:52:26.188 T:3761271664   DEBUG: Thread FileCache start, auto delete: false
14:52:26.194 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:85534 dts:4537.739 pts:4537.779 dur:40.000ms, clock:4529.083 level:107
14:52:26.199 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:40472 dts:4537.779 pts:4538.059 dur:40.000ms, clock:4529.083 level:107
14:52:26.200 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:21625 dts:4537.819 pts:4537.899 dur:40.000ms, clock:4529.083 level:107
14:52:26.215 T:3459216240   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
14:52:26.215 T:3568296816   DEBUG: CDVDAudio::Pause - pausing audio stream
14:52:26.215 T:3459216240   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
14:52:26.215 T:3568296816   DEBUG: CDVDAudio::Resume - resume audio stream
14:52:26.217 T:4069393264   DEBUG: ActiveAE - start sync of audio stream
14:52:26.219 T:4061000560    INFO: CActiveAESink::OpenSink - initialize sink
14:52:26.219 T:4061000560   DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:default
14:52:26.219 T:4061000560    INFO: CAESinkALSA::Initialize - Requested layout: FL, FR
14:52:26.219 T:4061000560    INFO: CAESinkALSA::Initialize - Attempting to open device "default"
14:52:26.225 T:4061000560    INFO: CAESinkALSA::Initialize - Opened device "default"
14:52:26.225 T:3459216240   DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
14:52:26.227 T:4061000560    INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
14:52:26.227 T:4061000560    INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
14:52:26.227 T:4061000560   DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 4096, bufferSize 16384
14:52:26.229 T:4061000560   DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 4096, bufferSize 16384
14:52:26.229 T:4061000560   DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 342 ms
14:52:26.230 T:4061000560    INFO: CAESinkALSA::Initialize - setting default aud_ch to 0
14:52:26.230 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:9033 dts:4537.859 pts:4537.859 dur:40.000ms, clock:4529.098 level:108
14:52:26.232 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:85698 dts:4537.899 pts:4537.939 dur:40.000ms, clock:4529.100 level:109
14:52:26.232 T:4061000560   DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
14:52:26.233 T:4061000560   DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL, FR
14:52:26.233 T:4061000560   DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL, FR (ALSA: none) (CEA: 0)
14:52:26.233 T:4061000560   DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
14:52:26.233 T:4061000560   DEBUG:   Output Device : Default (AML-M8AUDIO Analog)
14:52:26.233 T:4061000560   DEBUG:   Sample Rate   : 48000
14:52:26.233 T:4061000560   DEBUG:   Sample Format : AE_FMT_S32NE
14:52:26.233 T:4061000560   DEBUG:   Channel Count : 2
14:52:26.233 T:4061000560   DEBUG:   Channel Layout: FL, FR
14:52:26.233 T:4061000560   DEBUG:   Frames        : 4096
14:52:26.233 T:4061000560   DEBUG:   Frame Size    : 8
14:52:26.235 T:3459216240   DEBUG: CVideoPlayer::ProcessVideoData size:13618 dts:4537.939 pts:4537.979 dur:40.000ms, clock:4529.103 level:109
14:52:26.246 T:3761271664    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
phunkyfish commented 5 years ago

Can you try increasing the cache size and mode using advancedsettings.xml and see if it helps?

Try something like example 4 here: https://kodi.wiki/view/HOW-TO:Modify_the_video_cache

sidey79 commented 5 years ago

Sorry, that doesn't really help

phunkyfish commented 5 years ago

Do you ever see timeout waiting for buffer without an EPG Refresh?

phunkyfish commented 5 years ago

Posting a full debug log would be useful.

sidey79 commented 5 years ago

Do you ever see timeout waiting for buffer without an EPG Refresh?

I found no option to diable epg refresh, but i found these timeout messages always after an epg refresh and not related to other messages.

What missing in the debug logfile i send?

phunkyfish commented 5 years ago

Context, I don't know what platform, versions or settings are in use from the snippet you posted. It's best to enable debug logging, restart, repro and then use a paste service to post the log (such as pastebinit).

phunkyfish commented 5 years ago

You can change the refresh for EPG in the kodi PVR settings (i.e. not the addon settings).

sidey79 commented 5 years ago

Some additional log lines. Sorry that i do not updload the complete logfile, but there are some sensitive information inside

00:33:53.069 T:4089234208  NOTICE: Starting Kodi (18.0-RC2 Git:18.0rc2-Leia). Platform: Linux ARM 32-bit
00:33:53.069 T:4089234208  NOTICE: Using Release Kodi x32 build
00:33:53.069 T:4089234208  NOTICE: Kodi compiled Dec  4 2018 by GCC 8.2.0 for Linux ARM 32-bit version 3.14.29 (200221)
00:33:53.069 T:4089234208  NOTICE: Running on CoreELEC (official): 8.95.6 (9.0), kernel: Linux ARM 64-bit version 3.14.29 aarch64
00:33:53.069 T:4089234208  NOTICE: FFmpeg version/source: 4.0.3-Kodi
00:33:53.070 T:4089234208  NOTICE: Host CPU: AArch64 Processor rev 4 (aarch64), 4 cores available
00:33:53.070 T:4089234208  NOTICE: ARM Features: Neon enabled
00:40:34.705 T:4089516832  NOTICE: Contents of special://xbmc/system/advancedsettings.xml are...
                                            <?xml version="1.0" encoding="utf-8" ?>
                                            <advancedsettings>
                                              <cputempcommand>/usr/bin/cputemp</cputempcommand>
                                              <gputempcommand>/usr/bin/gputemp</gputempcommand>
                                              <showexitbutton>false</showexitbutton>
                                              <remotedelay>1</remotedelay>
                                              <samba>
                                                <clienttimeout>30</clienttimeout>
                                              </samba>
                                              <splash>false</splash>
                                            </advancedsettings>
00:40:34.705 T:4089516832 WARNING: CSettingsManager: missing version attribute
00:40:34.706 T:4089516832  NOTICE: Loaded settings file from special://profile/advancedsettings.xml
00:40:34.707 T:4089516832  NOTICE: Contents of special://profile/advancedsettings.xml are...
                                            <?xml version="1.0" encoding="utf-8" ?>
                                            <advancedsettings>
                                              <cache>
                                                <buffermode>1</buffermode>
                                                <memorysize>139460608</memorysize>
                                                <readfactor>20</readfactor>
                                              </cache>
                                            </advancedsettings>
00:40:34.707 T:4089516832 WARNING: CSettingsManager: missing version attribute

00:40:34.870 T:4089516832    INFO: ADDON: cpluff: 'Could not read plug-in directory /usr/lib/kodi/addons: No such file or directory'
00:40:34.871 T:4089516832   DEBUG: ADDON: cpluff: 'Not all directories were successfully scanned.'
00:40:34.871 T:4089516832  NOTICE: ADDON: audioencoder.kodi.builtin.aac v1.0.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: audioencoder.kodi.builtin.wma v1.0.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: driver.dvb.crazycat_aml v9.0.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: driver.dvb.dvb-latest v9.0.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: game.controller.default v1.0.8 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: game.controller.snes v1.0.8 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: imagedecoder.raw v2.0.0.3 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: inputstream.adaptive v2.3.12.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: inputstream.rtmp v2.0.4.0 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: kodi.binary.global.audioengine v1.0.1 installed
00:40:34.871 T:4089516832  NOTICE: ADDON: kodi.binary.global.filesystem v1.0.2 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.global.general v1.0.3 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.global.gui v5.12.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.global.main v1.0.13 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.global.network v1.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.audiodecoder v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.audioencoder v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.game v1.1.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.imagedecoder v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.inputstream v2.0.8 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.peripheral v1.3.7 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.pvr v5.10.4 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.screensaver v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.vfs v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.videocodec v1.0.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.binary.instance.visualization v2.0.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: kodi.resource v1.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.album.universal v3.1.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.artists.universal v4.2.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.allmusic.com v3.2.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.fanart.tv v3.5.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.imdb.com v3.1.4 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.musicbrainz.org v2.2.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.theaudiodb.com v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.common.themoviedb.org v3.1.8 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.local v1.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.themoviedb.org v5.1.4 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.tvdb.com v3.0.14 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: metadata.tvshows.themoviedb.org v3.1.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: os.libreelec.tv v9.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: os.openelec.tv v9.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: peripheral.joystick v1.4.6.2 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: plugin.program.browser.launcher v1.2.4 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: plugin.video.amazon v2.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: plugin.video.kikamediathek v1.0.0 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: pvr.vuplus v3.15.4.2 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.coreelec v9.0.2 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.kodinerds v8.1.103.103 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.kodinerds_Odroid_C2 v1.0.3 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.linuxserver.docker v9.0.103.103 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.sandmann79.plugins v1.0.2 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: repository.xbmc.org v3.1.4 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: resource.images.weathericons.default v1.1.8 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: resource.language.de_de v9.0.15 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: resource.language.en_gb v2.0.1 installed
00:40:34.872 T:4089516832  NOTICE: ADDON: resource.uisounds.kodi v1.0.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: screensaver.xbmc.builtin.black v1.0.32 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: screensaver.xbmc.builtin.dim v1.0.48 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.amazon.database v0.1.1 installed

00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.beautifulsoup v3.2.1 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.certifi v2017.07.27.1 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.chardet v3.0.4 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.future v0.16.0.4 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.googleapi v1.6.4 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.httplib2 v0.10.3 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.idna v2.6 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.inputstreamhelper v0.3.3 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.kodi-six v0.0.2 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.libkika v1.0.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.libmdr v1.0.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.libmediathek3 v1.5.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.mechanize v0.2.6 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.myconnpy v1.1.7 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.oauth2client v4.1.2 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.pil v1.1.7 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.pycryptodome v3.4.3 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.pydes v2.0.1 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.pyxbmct v1.3.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.requests v2.19.1 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.six v1.11.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.uritemplate v0.6.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.urllib3 v1.22 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.module.yaml v3.11.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.openweathermap.maps v0.2.2 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.program.driverselect v0.1.6.101 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: script.xbmcbackup v1.1.2 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: service.coreelec.settings v9.0.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: service.fhemcinema v0.3.3 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: skin.estuary v2.0.16 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: vfs.rar v2.0.5.2 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: weather.yahoo v4.3.1 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: webinterface.default v18.x-2.4.6 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.addon v17.9.920 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.core v0.1.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.gui v5.14.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.json v10.0.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.metadata v2.1.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.python v2.26.0 installed
00:40:34.873 T:4089516832  NOTICE: ADDON: xbmc.webinterface v1.0.0 installed
00:40:34.900 T:4089516832   DEBUG: ADDON: Dll Initializing - RAR archive support
00:40:35.012 T:4089516832  NOTICE: EGL_VERSION = 1.4 Linux-r5p1-01rel0
00:40:35.012 T:4089516832  NOTICE: EGL_VENDOR = ARM
00:40:35.012 T:4089516832  NOTICE: EGL_EXTENSIONS = EGL_KHR_image EGL_KHR_image_base EGL_KHR_image_pixmap EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_reusable_sync EGL_KHR_fence_sync
 EGL_KHR_lock_surface EGL_KHR_lock_surface2 EGL_EXT_create_context_robustness EGL_ANDROID_blob_cache EGL_KHR_create_context
00:40:35.012 T:4089516832  NOTICE: EGL_CLIENT_EXTENSIONS = NULL
00:40:35.012 T:4089516832   DEBUG: EGL Config Attributes:
00:40:35.012 T:4089516832   DEBUG:   EGL_BUFFER_SIZE: 32
00:40:35.012 T:4089516832   DEBUG:   EGL_ALPHA_SIZE: 8
00:40:35.012 T:4089516832   DEBUG:   EGL_BLUE_SIZE: 8
00:40:35.012 T:4089516832   DEBUG:   EGL_GREEN_SIZE: 8
00:40:35.012 T:4089516832   DEBUG:   EGL_RED_SIZE: 8
00:40:35.012 T:4089516832   DEBUG:   EGL_DEPTH_SIZE: 24
00:40:35.012 T:4089516832   DEBUG:   EGL_STENCIL_SIZE: 8
00:40:35.012 T:4089516832   DEBUG:   EGL_CONFIG_CAVEAT: 0x3038
00:40:35.012 T:4089516832   DEBUG:   EGL_CONFIG_ID: 9
00:40:35.012 T:4089516832   DEBUG:   EGL_LEVEL: 0
00:40:35.012 T:4089516832   DEBUG:   EGL_MAX_PBUFFER_HEIGHT: 4096
00:40:35.012 T:4089516832   DEBUG:   EGL_MAX_PBUFFER_PIXELS: 16777216
00:40:35.012 T:4089516832   DEBUG:   EGL_MAX_PBUFFER_WIDTH: 4096
00:40:35.012 T:4089516832   DEBUG:   EGL_NATIVE_RENDERABLE: 1
00:40:35.012 T:4089516832   DEBUG:   EGL_NATIVE_VISUAL_ID: 0
00:40:35.012 T:4089516832   DEBUG:   EGL_NATIVE_VISUAL_TYPE: 0
00:40:35.012 T:4089516832   DEBUG:   EGL_SAMPLES: 0
00:40:35.012 T:4089516832   DEBUG:   EGL_SAMPLE_BUFFERS: 0
00:40:35.012 T:4089516832   DEBUG:   EGL_SURFACE_TYPE: 1031
00:40:35.012 T:4089516832   DEBUG:   EGL_TRANSPARENT_TYPE: 0x3038
00:40:35.012 T:4089516832   DEBUG:   EGL_TRANSPARENT_BLUE_VALUE: -1
00:40:35.012 T:4089516832   DEBUG:   EGL_TRANSPARENT_GREEN_VALUE: -1
00:40:35.012 T:4089516832   DEBUG:   EGL_TRANSPARENT_RED_VALUE: -1
00:40:35.012 T:4089516832   DEBUG:   EGL_BIND_TO_TEXTURE_RGB: 1
00:40:35.012 T:4089516832   DEBUG:   EGL_BIND_TO_TEXTURE_RGBA: 1
00:40:35.013 T:4089516832   DEBUG:   EGL_MIN_SWAP_INTERVAL: 0
00:40:35.013 T:4089516832   DEBUG:   EGL_MAX_SWAP_INTERVAL: 10
00:40:35.013 T:4089516832   DEBUG:   EGL_LUMINANCE_SIZE: 0
00:40:35.013 T:4089516832   DEBUG:   EGL_ALPHA_MASK_SIZE: 0
00:40:35.013 T:4089516832   DEBUG:   EGL_COLOR_BUFFER_TYPE: 0x308e
00:40:35.013 T:4089516832   DEBUG:   EGL_RENDERABLE_TYPE: 5
00:40:35.013 T:4089516832   DEBUG:   EGL_CONFORMANT: 5
M2k80 commented 5 years ago

the only reason for not uploading complete debug log is using blacklisted addons ^^

sidey79 commented 5 years ago

I have no Idea what are Blacklisted addons and who defined them.

phunkyfish commented 5 years ago

In fairness it could just be login information. If you do have blacklisted addons these would be any addons that are used to access pirated content etc.

If you have installed kodi from an official site and only use kodi repo addons you are safe. If you install kodi from unofficial sources that come prepackaged with loads of plugins then it’s very hard to tell what’s ok and what’s not.

On 2 Jan 2019, at 09:47, sidey79 notifications@github.com wrote:

I have no Idea what are Blacklisted addons and who uploaded them.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

sidey79 commented 5 years ago

I've installed https://coreelec.org/ I hope this is nothing unusal or blacklisted.

But in the debug logs are some private information i do not want to share public in the internet without any control.

M2k80 commented 5 years ago

This cant be so much, why not only remove this “private informations” with

Am Mi., 2. Jan. 2019, 22:09 hat sidey79 notifications@github.com geschrieben:

I've installed https://coreelec.org/ I hope this is nothing unusal or blacklisted.

But in the debug logs are some private information i do not want to share public in the internet without any control.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/kodi-pvr/pvr.vuplus/issues/158#issuecomment-450985757, or mute the thread https://github.com/notifications/unsubscribe-auth/AF2m1Dgxy7OnpzmeWsYbrDtT3sO9vT-iks5u_SATgaJpZM4Zl6Nh .

sidey79 commented 5 years ago

Pastebin doesn't allows me to upload so much data:

I've tested a littlebit around and found out some things

  1. I've configured a epg refresh interval of 120 minutes. (default setting)
  2. Update during playback should be disabled (default setting)
  3. Disabeling epg refresh completly is not possible

I've cleared the epg cache and restarted Kodi to get this logs:

kodi-epg-pvr-vuplus.txt

You can see there, while the epg refresh is running, i have buffer timeout errros. The last WaitForBuffer - timeout waiting for buffer is at 23:19:54.408

The last EPG action is at 23:20:00.845 T:3626193776 during playback. After this, no buffer timeout errors occure anymore.

I'm stopping playback at 23:33:21.077 T:3637318512 and soon after this, epg starts to refresh again.

I've checked this (not in the logs) epg refresh will restart every time after a playback is stopped. If i then start a new playback i get those buffer timeout errors until epg refresh is finished.

So there are three bugs i think:

  1. EPG refresh shoud be paused during playback
  2. epg refresh disrupts playback
  3. epg refresh starts befor the refresh interval is reached
phunkyfish commented 5 years ago

An EPG refresh is initiated by the PVR backend. The fact that the default is to disable during playback I’m not sure 2 is a bug. Number 3 might just be a different channel. I’ll do a bit more digging through your log tomorrow.

phunkyfish commented 5 years ago

Ok, I’m not sure 1) is an issue.m after reviewing the log. When kodi starts up it will load the EPG for each channel (this is not a refresh it’s an initial load). This takes a few mins. After that it will respect the EPG refresh when playing back.

Does this only happen after a restart or at other times also?

Does that make sense @sidey79 ?

sidey79 commented 5 years ago

From my point of view it makes no sens to allow the inital epg load and to disable only the refresh. I have those playback disruptions also during playjack.

I'll change epg refresh to 15 minutes and verify the logs with following scenarious 1) live tv 2) playback of recorded video

Will be back soon

sidey79 commented 5 years ago

okay i did my tests

During playpack (live or recording) there occures no no epg update after 15 Minutes. I hope it took my configuration.

If a epg update is running, then playback via live and recording is disrupted. Seems to be to much requests in to short time.

sidey79 commented 5 years ago

Another note

While not doing any playback it seems to refresh every 5 minutes instead of configured 15 minutes

23:48:45.087 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Got result. Length: 168472
23:48:45.122 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Loaded 0 EPG Entries for channel 'SIXX HD'
23:48:45.125 T:3704087408   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'SIXX HD'
23:48:45.125 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A
EF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A'
23:48:45.125 T:3704087408   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
23:48:45.126 T:3704087408   DEBUG: CurlFile::Open(0xeede7080) http://AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3AEF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A
23:48:46.486 T:3175842672   DEBUG: Thread FileCache start, auto delete: false
23:48:46.508 T:3175842672    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
23:48:46.510 T:3175842672   DEBUG: Thread FileCache 3175842672 terminating
23:48:46.510 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Got result. Length: 168472
23:48:46.531 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Loaded 0 EPG Entries for channel 'SIXX HD'
23:48:46.533 T:3704087408   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'SIXX HD'
23:48:46.533 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A
EF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A'
22:41:33.687 T:3704087408   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
22:41:33.689 T:3704087408   DEBUG: CurlFile::Open(0xd813f338) http://AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A285B%3A401%3A1%3AC00000%3A0%3A0%3A0%3A
23:53:46.431 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Loaded 0 EPG Entries for channel 'SIXX HD'
23:53:46.433 T:3704087408   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'SIXX HD'
23:53:46.434 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A
EF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A'
23:53:46.434 T:3704087408   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
23:53:46.434 T:3704087408   DEBUG: CurlFile::Open(0xeeda0530) http://AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3AEF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A
23:53:47.403 T:3323700080  NOTICE: [Amazon] getURL: https://atv-ps-eu.amazon.de/cdp/catalog/Browse?firmware=fmw:17-app:2.0.45.1210&deviceTypeID=A2M4YX06LWP8WI&deviceID=7c
8462f08636b05a7193b46bac8dca11e7732f4aded74fd72c061adf&format=json&StartIndex=700&NumberOfResults=140&ContentType=TVEpisode&RollUpToSeason=T&OrderBy=Title&OfferGroups=B00
43YVHMY&ContractID=UX*&IncludeBlackList=T&HideNum=T&AID=1&IncludeNonWeb=T&IncludeAll=T&version=2
23:53:47.833 T:3922875248   DEBUG: Thread FileCache start, auto delete: false
23:53:47.855 T:3922875248    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
23:53:47.907 T:3922875248   DEBUG: Thread FileCache 3922875248 terminating
23:53:47.907 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Got result. Length: 168472
23:53:47.927 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Loaded 0 EPG Entries for channel 'SIXX HD'
23:53:47.929 T:3679449968    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/deviceinfo'
23:53:47.930 T:3679449968   DEBUG: CFileCache::Open - opening <web/deviceinfo> using cache
23:53:47.930 T:3679449968   DEBUG: CurlFile::Open(0xde3fee28) http://AA.BB.CC.DD:80/web/deviceinfo
23:53:47.931 T:3704087408   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'SIXX HD'
23:53:47.931 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A
EF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A'
23:53:47.932 T:3704087408   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
23:53:47.932 T:3704087408   DEBUG: CurlFile::Open(0xeeda0530) http://AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3AEF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A
23:53:48.174 T:3922875248   DEBUG: Thread FileCache start, auto delete: false
23:53:48.175 T:3922875248    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
23:53:48.176 T:3922875248   DEBUG: Thread FileCache 3922875248 terminating
23:53:48.176 T:3679449968    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Got result. Length: 1253
23:53:48.180 T:3679449968    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetDriveSpace Total: 1932735283, Used 341521203
23:53:49.607 T:3922875248   DEBUG: Thread FileCache start, auto delete: false
23:53:49.641 T:3922875248    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
23:53:49.684 T:3679449968    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/deviceinfo'
23:53:49.684 T:3679449968   DEBUG: CFileCache::Open - opening <web/deviceinfo> using cache
23:53:49.684 T:3679449968   DEBUG: CurlFile::Open(0xde3fee28) http://AA.BB.CC.DD:80/web/deviceinfo
23:53:49.691 T:3922875248   DEBUG: Thread FileCache 3922875248 terminating
23:53:49.692 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Got result. Length: 168472
23:53:49.712 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Loaded 0 EPG Entries for channel 'SIXX HD'
23:53:49.715 T:3704087408   DEBUG: AddOnLog: Enigma2 Client: pvr.vuplus - GetEPGForChannel Getting EPG for channel 'SIXX HD'
23:53:49.715 T:3704087408    INFO: AddOnLog: Enigma2 Client: pvr.vuplus - GetHttpXML Open webAPI with URL: 'http://XXX:YYY@AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3A
EF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A'
23:53:49.715 T:3704087408   DEBUG: CFileCache::Open - opening <web/epgservice> using cache
23:53:49.716 T:3704087408   DEBUG: CurlFile::Open(0xeeda0530) http://AA.BB.CC.DD:80/web/epgservice?sRef=1%3A0%3A19%3AEF77%3A3F9%3A1%3AC00000%3A0%3A0%3A0%3A
23:53:49.927 T:3922875248   DEBUG: Thread FileCache start, auto delete: false
23:53:49.927 T:3922875248    INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?)
phunkyfish commented 5 years ago

Interesting. Let me check the same on my system.

How many channels do you have and what is the total duration of a full refresh?

sidey79 commented 5 years ago

24 channels in that bouquet and it seems to take about 2 minutes to do a epg refresh

phunkyfish commented 5 years ago

cool, i’ll measure the same in my test

phunkyfish commented 5 years ago

Ok, I’ve tested this over the last two hours. I set the update interval to fifteen minutes.

In the first 45 mins I watched a channel and allowed updates while playing back. EPG updated for 150 channels in less that 1 minute each time and occurred each 15 minutes. There was no interruption to playback.

For the next 45 mins I disabled updates during playback and they didn’t happen.

For the last 30 mins I stopped playback and the updates occurred again each 15 mins.

phunkyfish commented 5 years ago

I even started playback during an EPG update and it paused it until I stopped playback.

phunkyfish commented 5 years ago

Are you using Ethernet or Wi-Fi?

M2k80 commented 5 years ago

@sidey79 as i can see, actually you use RC2 of leia, you should update to latest RC4 or nightly coreelec build. from 4.dec until today was many changes to leia. i saw some fixes about slow network speed.

@phunkyfish some offtopic: did you see this

23:17:22.705 T:3990016880   DEBUG: CAddonSettings[pvr.vuplus]: failed to find definition for setting onegroup. Creating a setting on-the-fly...
23:17:22.705 T:3990016880   DEBUG: CSettingsManager: requested setting (onlyonegroup) was not found.
23:17:22.705 T:3990016880   DEBUG: CAddonSettings[pvr.vuplus]: failed to find definition for setting onlyonegroup. Creating a setting on-the-fly...
23:17:22.705 T:3990016880   DEBUG: CSettingsManager: requested setting (setpowerstate) was not found.
23:17:22.705 T:3990016880   DEBUG: CAddonSettings[pvr.vuplus]: failed to find definition for setting setpowerstate. Creating a setting on-the-fly...
23:17:22.706 T:3990016880   DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'Enigma2 Client' requests setting 'autoconfig'

wasnt this happened cause of an old settings.xml? do you remember from my settings.xml?

sidey79 commented 5 years ago

I'm using ethernet all the way, no wifi. But my receiver has only a 100 mbit interface. no idea what you mean with the settings.xml.

I'll test with newest coreelec.

M2k80 commented 5 years ago

@sidey79 with the settings.xml was only for @phunkyfish - thats why i said offtopic, it has nothing to do with this issue

phunkyfish commented 5 years ago

Those are 4 settings that are no longer read from the addon. They can be removed from the settings.xml: extracteventinfo, onegroup, onlyonegroup, setpowerstate

They won't cause any harm though.

phunkyfish commented 5 years ago

@sidey79 do you have to use CoreElec? Is it the only one that supports your platform?

M2k80 commented 5 years ago

i get this sometimes too WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer but i didnt watched through the debug log, because i thought this might be happen through bad signal from my cable provider. i get sometimes short pixelation or worst case it shortly buffers 0-5% 5 or six times - i will now take a look at the debug log, if that happens when epg is loading

phunkyfish commented 5 years ago

I used to get some minor buffering but similar to you but not since I added an advancedsettings.xml. I run a Nuc7pjyh with 8GB of RAM and this advancedsettings.xml

<advancedsettings>
  <cache>
    <buffermode>1</buffermode>
    <memorysize>838860800</memorysize>
    <readfactor>4.0</readfactor>
  </cache>
</advancedsettings>
sidey79 commented 5 years ago

I started wird libreelec but figured out, that this does support 32 bit user space on my Odroid c2. So i am now on coreelec because this fits netter on my plattform. Die you think the problems i have are comming from coreelec?

phunkyfish commented 5 years ago

I don’t think so, it’s just coreelec updates their kodi less often that the libreElec nightlies.

If you are having buffering issues it’s most likely they are fixed by kodi and not the addon.

RC2 was quite a while ago.

phunkyfish commented 5 years ago

In saying that it’s entirely possible LibreELEC doesn’t do nightlies for Odroid, I don’t really know. There are so many ARM devices now it gets confusing.

sidey79 commented 5 years ago

I've tested newest coreelec today

Tested playback of recording:

While EPG refresh runs, i have still playback issues. CPU from my Enigma2 Receiver has a load of 0.9. So cpu power of one core is almost used. If EPG refresh is finished, load is about 0.3. I think, the webif isn't the fastest enigma2 addon and the high request rate is a little bit to much for my enigma2 receiver.

While playback, epgrefesh seems not to start again. When stopping playback, the epg refresh is triggered still before the configured refresh interaval.

phunkyfish commented 5 years ago

If you stop playback the refresh will happen immediately if there was one due during playback.

There is a lot of logging around refreshes which may exacerbate the problem in debug mode.

Can you try again with debug mode off with the new release?

On 5 Jan 2019, at 22:20, sidey79 notifications@github.com wrote:

I've tested newest coreelec today

Kodi v18 Leia (Release Candidate 4) based on LibreELEC/master (01/01/19) Tested playback of recording:

While EPG refresh runs, i have still playback issues. CPU from my Enigma2 Receiver has a load of 0.9. So cpu power of one core is almost used. If EPG refresh is finished, load is about 0.3. I think, the webif isn't the fastest enigma2 addon and the high request rate is a little bit to much for my enigma2 receiver.

While playback, epgrefesh seems not to start again. When stopping playback, the epg refresh is triggered still before the configured refresh interaval.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or mute the thread.

sidey79 commented 5 years ago

Okay without debug enabled starting / stopping is not triggering a new epg refresh.

phunkyfish commented 5 years ago

Very strange, I have no idea why that is.

Do you have another device such as Windows or Mac machine that can view the same channel on kodi at the same time?

If playback is perfect there but buffers on corelelec it may be the kodi ARM device that is struggling.

sidey79 commented 5 years ago

I've 17.6 on a windows machine, but there is no access to recordings because there is no udate to a newer version of the addon available. I'll try Leia RC4

sidey79 commented 5 years ago

Tested with my windows kodi leia RC4.

If my windows machine starts epg refresh my odroid c2 gets disrupted. The windows machine also.

If my odroid c2 starts an epg refresh, my windows machine also gets interrupted. So i think this is not a odroid c2 specific problem.

phunkyfish commented 5 years ago

Ok, so that proves for sure that your STB is under pressure.

The calls to GetEPGForChannel are sequential. Maybe we can put a delay between each one to have less pressure on your STB.

But this would only work if a single channel refresh doesn’t cause this.

Is it easy for you to do the following test? Create a bouquet with a single channel and only load that in the addon. Then view that channel and see if a refresh causes a buffer issue. If it’s only that a delay between calls should work.

sidey79 commented 5 years ago

I'll try this, but i think this will work, because i do not get an interruption per channel.w

phunkyfish commented 5 years ago

Did you get to test this? Let me know as I’ll preparing the next PR now. May not do another for a few weeks.

sidey79 commented 5 years ago

It's not very easy to test valid with a single channel. But as expected there are very less requests, having only one channel in the bouquete. But in this scenario i did not get an interruption.

phunkyfish commented 5 years ago

Ok, I’ll add the delay in the next PR and you can try it out.

phunkyfish commented 5 years ago

So in 3.16.2. there will be an addon setting under EPG so that can set a delay from 250ms to 5000ms between channel updates. Let me know if it works!

sidey79 commented 5 years ago

@phunkyfish Thanky. Should i try to update with the pull request?

phunkyfish commented 5 years ago

The addon is binary so you’ll need to wait for the next CoreElec build after the PR is approved.

Not sure how frequent they are. You could also test with a windows build of course.