Win [FIXED] Kodi 15.2 Random Playback Freezes And Return To Menu
Automan
Junior Member
Posts: 17
#1
2015-12-25, 21:22
I have been using Kodi for quite some time on an Android box but wanted to get more sound formats e.g. DTS-HD Master Audio

To this end I got an Acer Revo One RL85
Code:
17:29:07 T:6040  NOTICE: special://profile/ is mapped to: special://masterprofile/
17:29:07 T:6040  NOTICE: -----------------------------------------------------------------------
17:29:07 T:6040  NOTICE: Starting Kodi (15.2 Git:20151019-02e7013). Platform: Windows NT x86 32-bit
17:29:07 T:6040  NOTICE: Using Release Kodi x32 build
17:29:07 T:6040  NOTICE: Kodi compiled Oct 19 2015 by MSVC 180030723 for Windows NT x86 32-bit version 6.0 (0x06000000)
17:29:07 T:6040  NOTICE: Running on Acer Revo One RL85 with Windows 10, kernel: Windows NT x86 64-bit version 10.0
17:29:07 T:6040  NOTICE: Host CPU: Intel(R) Core(TM) i3-5010U CPU @ 2.10GHz, 4 cores available
17:29:07 T:6040  NOTICE: Desktop Resolution: 1920x1080 32Bit at 59Hz
17:29:07 T:6040  NOTICE: Running with restricted rights
17:29:07 T:6040  NOTICE: Aero is enabled
17:29:07 T:6040  NOTICE: special://xbmc/ is mapped to: C:\Program Files (x86)\Kodi
17:29:07 T:6040  NOTICE: special://xbmcbin/ is mapped to: C:\Program Files (x86)\Kodi
17:29:07 T:6040  NOTICE: special://masterprofile/ is mapped to: C:\Users\Ian\AppData\Roaming\Kodi\userdata
17:29:07 T:6040  NOTICE: special://home/ is mapped to: C:\Users\Ian\AppData\Roaming\Kodi\
17:29:07 T:6040  NOTICE: special://temp/ is mapped to: C:\Users\Ian\AppData\Roaming\Kodi\cache
17:29:07 T:6040  NOTICE: The executable running is: C:\Program Files (x86)\Kodi\Kodi.exe
17:29:07 T:6040  NOTICE: Local hostname: TV-PC
17:29:07 T:6040  NOTICE: Log File is located: C:\Users\Ian\AppData\Roaming\Kodi\kodi.log
17:29:07 T:6040  NOTICE: -----------------------------------------------------------------------
17:29:07 T:6040  NOTICE: load settings...
17:29:07 T:5516  NOTICE: Thread CWin32PowerStateWorker start, auto delete: false
17:29:07 T:6040 WARNING: CSettingString: unknown options filler "timezonecountries" of "locale.timezonecountry"
17:29:07 T:6040 WARNING: CSettingString: unknown options filler "timezones" of "locale.timezone"
17:29:07 T:6040  NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)
17:29:07 T:6040  NOTICE: No settings file to load (special://masterprofile/advancedsettings.xml)
17:29:07 T:6040  NOTICE: Default DVD Player: dvdplayer
17:29:07 T:6040  NOTICE: Default Video Player: dvdplayer
17:29:07 T:6040  NOTICE: Default Audio Player: paplayer
17:29:07 T:6040  NOTICE: Enabled debug logging due to GUI setting (2)
17:29:07 T:6040  NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM"

Anyway, typically everything works well except sometimes, apprantly random, playback of files from my locally networked WD DL4100 NAS just stops.

Picture will pause, "I" and "O" key still works and then after a while you are returned to the Kodi Menu.

You can then just resume playback again with out any issues (unless it happens near the end in which case you have to zoom to the point in the recording manually).

I have turned on full logging and after just over an hour into a film (it can be under 5 minutes) the problem occurred.

Code:
17:41:23 T:6040  NOTICE: DVDPlayer: Opening: smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv
17:41:23 T:6040 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
17:41:23 T:6040   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
17:41:23 T:8976  NOTICE: Thread DVDPlayer start, auto delete: false
17:41:23 T:8976  NOTICE: Creating InputStream
17:41:23 T:8976   DEBUG: CUtil::ScanForExternalSubtitles: Searching for subtitles...
17:41:23 T:8976   DEBUG: CUtil::ScanForExternalSubtitles: END (total time: 7 ms)
17:41:23 T:8976  NOTICE: Creating Demuxer
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::Open - probing detected format [matroska,webm]
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::Open - avformat_find_stream_info starting
17:41:23 T:8976   DEBUG: ffmpeg[2310]: [matroska,webm] Could not find codec parameters for stream 2 (Subtitle: hdmv_pgs_subtitle): unspecified size
17:41:23 T:8976   DEBUG: ffmpeg[2310]: [matroska,webm] Consider increasing the value for the 'analyzeduration' and 'probesize' options
17:41:23 T:8976   DEBUG: ffmpeg[2310]: [matroska,webm] Could not find codec parameters for stream 3 (Subtitle: hdmv_pgs_subtitle): unspecified size
17:41:23 T:8976   DEBUG: ffmpeg[2310]: [matroska,webm] Consider increasing the value for the 'analyzeduration' and 'probesize' options
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info finished
17:41:23 T:8976    INFO: ffmpeg[2310]: Input #0, matroska,webm, from 'smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv':
17:41:23 T:8976    INFO: ffmpeg[2310]:   Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:     title           : The King and I
17:41:23 T:8976    INFO: ffmpeg[2310]:     encoder         : libmakemkv v1.9.8 (1.3.3/1.4.4) win(x64-release)
17:41:23 T:8976    INFO: ffmpeg[2310]:     creation_time   : 2015-12-24 22:59:31
17:41:23 T:8976    INFO: ffmpeg[2310]:   Duration: 02:13:18.70, start: 0.000000, bitrate: 33441 kb/s
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:0: start 0.000000, end 114.447667
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 01
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:1: start 114.447667, end 261.719792
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 02
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:2: start 261.719792, end 381.089042
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 03
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:3: start 381.089042, end 550.758542
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 04
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:4: start 550.758542, end 621.037083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 05
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:5: start 621.037083, end 764.054958
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 06
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:6: start 764.054958, end 885.718167
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 07
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:7: start 885.718167, end 1074.406667
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 08
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:8: start 1074.406667, end 1352.768083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 09
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:9: start 1352.768083, end 1492.866375
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 10
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:10: start 1492.866375, end 1711.126083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 11
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:11: start 1711.126083, end 1828.159667
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 12
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:12: start 1828.159667, end 2058.681625
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 13
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:13: start 2058.681625, end 2157.864042
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 14
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:14: start 2157.864042, end 2843.048542
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 15
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:15: start 2843.048542, end 2886.300083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 16
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:16: start 2886.300083, end 3182.596083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 17
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:17: start 3182.596083, end 3325.030042
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 18
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:18: start 3325.030042, end 3555.760542
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 19
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:19: start 3555.760542, end 3649.228917
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 20
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:20: start 3649.228917, end 3790.620167
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 21
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:21: start 3790.620167, end 3884.171958
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 22
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:22: start 3884.171958, end 4088.084000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 23
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:23: start 4088.084000, end 4463.459000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 24
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:24: start 4463.459000, end 4622.618000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 25
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:25: start 4622.618000, end 4768.764000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 26
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:26: start 4768.764000, end 4892.971417
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 27
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:27: start 4892.971417, end 5074.736333
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 28
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:28: start 5074.736333, end 5283.820208
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 29
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:29: start 5283.820208, end 5376.162458
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 30
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:30: start 5376.162458, end 5487.023208
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 31
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:31: start 5487.023208, end 5561.305750
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 32
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:32: start 5561.305750, end 5724.927542
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 33
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:33: start 5724.927542, end 5984.061417
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 34
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:34: start 5984.061417, end 6012.006000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 35
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:35: start 6012.006000, end 6135.129000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 36
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:36: start 6135.129000, end 6163.699208
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 37
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:37: start 6163.699208, end 6358.894208
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 38
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:38: start 6358.894208, end 6482.476000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 39
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:39: start 6482.476000, end 6674.834833
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 40
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:40: start 6674.834833, end 6800.502042
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 41
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:41: start 6800.502042, end 7018.011000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 42
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:42: start 7018.011000, end 7163.990167
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 43
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:43: start 7163.990167, end 7396.806083
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 44
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:44: start 7396.806083, end 7582.199625
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 45
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:45: start 7582.199625, end 7726.719000
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 46
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:46: start 7726.719000, end 7792.451333
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 47
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:47: start 7792.451333, end 7923.498917
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 48
17:41:23 T:8976    INFO: ffmpeg[2310]:     Chapter #0:48: start 7923.498917, end 7998.699042
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Chapter 49
17:41:23 T:8976    INFO: ffmpeg[2310]:     Stream #0:0(eng): Video: h264 (High), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       BPS-eng         : 3024455
17:41:23 T:8976    INFO: ffmpeg[2310]:       DURATION-eng    : 02:13:18.699041666
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_FRAMES-eng: 191777
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_BYTES-eng: 30239637750
17:41:23 T:8976    INFO: ffmpeg[2310]:       SOURCE_ID-eng   : 001011
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_APP-eng: MakeMKV v1.9.8 win(x64-release)
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_DATE_UTC-eng: 2015-12-24 22:59:31
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
17:41:23 T:8976    INFO: ffmpeg[2310]:     Stream #0:1(eng): Audio: dts (DTS-HD MA), 48000 Hz, 4.0, fltp, 1536 kb/s (default)
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       title           : Surround 4.0
17:41:23 T:8976    INFO: ffmpeg[2310]:       BPS-eng         : 312325
17:41:23 T:8976    INFO: ffmpeg[2310]:       DURATION-eng    : 02:13:18.709333333
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_FRAMES-eng: 749879
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_BYTES-eng: 3122755704
17:41:23 T:8976    INFO: ffmpeg[2310]:       SOURCE_ID-eng   : 001100
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_APP-eng: MakeMKV v1.9.8 win(x64-release)
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_DATE_UTC-eng: 2015-12-24 22:59:31
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
17:41:23 T:8976    INFO: ffmpeg[2310]:     Stream #0:2(eng): Subtitle: hdmv_pgs_subtitle
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       BPS-eng         : 3852
17:41:23 T:8976    INFO: ffmpeg[2310]:       DURATION-eng    : 02:10:55.535187500
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_FRAMES-eng: 3630
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_BYTES-eng: 37825488
17:41:23 T:8976    INFO: ffmpeg[2310]:       SOURCE_ID-eng   : 001200
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_APP-eng: MakeMKV v1.9.8 win(x64-release)
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_DATE_UTC-eng: 2015-12-24 22:59:31
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
17:41:23 T:8976    INFO: ffmpeg[2310]:     Stream #0:3(eng): Subtitle: hdmv_pgs_subtitle
17:41:23 T:8976    INFO: ffmpeg[2310]:     Metadata:
17:41:23 T:8976    INFO: ffmpeg[2310]:       BPS-eng         : 3396
17:41:23 T:8976    INFO: ffmpeg[2310]:       DURATION-eng    : 02:08:44.195645833
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_FRAMES-eng: 2107
17:41:23 T:8976    INFO: ffmpeg[2310]:       NUMBER_OF_BYTES-eng: 32796770
17:41:23 T:8976    INFO: ffmpeg[2310]:       SOURCE_ID-eng   : 001203
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_APP-eng: MakeMKV v1.9.8 win(x64-release)
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_WRITING_DATE_UTC-eng: 2015-12-24 22:59:31
17:41:23 T:8976    INFO: ffmpeg[2310]:       _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES SOURCE_ID
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::AddStream(2, ...) -> 2
17:41:23 T:8976   DEBUG: CDVDDemuxFFmpeg::AddStream(3, ...) -> 3
17:41:23 T:8976  NOTICE: Opening stream: 0 source: 256
17:41:23 T:8976  NOTICE: Creating video codec with codec id: 28
17:41:23 T:8976   DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no DXVA:yes iMXVPU:no MMAL:no
17:41:23 T:8976   DEBUG: FactoryCodec - Video:  - Opening
17:41:23 T:8976  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
17:41:23 T:8976   DEBUG: FactoryCodec - Video: ff-h264 - Opened
17:41:23 T:8976  NOTICE: Creating video thread
17:41:23 T:8976  NOTICE: Opening stream: 1 source: 256
17:41:23 T:8976  NOTICE: Finding audio codec for: 86020
17:41:23 T:8976   DEBUG: FactoryCodec - Audio: passthrough - Opening
17:41:23 T:8976   DEBUG: FactoryCodec - Audio: passthrough - Opened
17:41:23 T:8976  NOTICE: Creating audio thread
17:41:23 T:8976  NOTICE: Opening stream: 2 source: 256
17:41:23 T:8976   DEBUG: FactoryCodec - Overlay: FFmpeg Subtitle Decoder - Opening
17:41:23 T:8976   DEBUG: FactoryCodec - Overlay: FFmpeg Subtitle Decoder - Opened
17:41:23 T:9140  NOTICE: Thread DVDPlayerVideo start, auto delete: false
17:41:23 T:9140  NOTICE: running thread: video_thread
17:41:23 T:9140   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
17:41:23 T:8976   DEBUG: CEdl::ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv
17:41:23 T:8316  NOTICE: Thread DVDPlayerAudio start, auto delete: false
17:41:23 T:8316  NOTICE: running thread: CDVDPlayerAudio::Process()
17:41:23 T:8316   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
17:41:23 T:8976   DEBUG: CApplication::OnPlayBackStarted: play state was 1, starting 1
17:41:23 T:8976   DEBUG: CDVDPlayer::SetCaching - caching state 3
17:41:23 T:6040   DEBUG: CApplication::PlayFile: OpenFile succeed, play state 2
17:41:23 T:6040   DEBUG: CApplication::OnPlayBackStarted: play state was 2, starting 0
17:41:23 T:9140    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
17:41:23 T:8316    INFO: CAEStreamInfo::SyncDTS - dtsHD stream detected (6 channels, 48000Hz, 16bit BE, period: 8192)
17:41:23 T:8316  NOTICE: Creating audio stream (codec id: 86020, channels: 8, sample rate: 192000, pass-through)
17:41:23 T:9140  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1920x1080)
17:41:23 T:9140   DEBUG: DXVA - open decoder
17:41:23 T:8316   DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
17:41:23 T:9140   DEBUG: DXVA - supports 'MPEG2 VLD'
17:41:23 T:9140   DEBUG: DXVA - supports 'MPEG2 IDCT'
17:41:23 T:9140   DEBUG: DXVA - supports E07EC519-e651-4cd6-ac84-1370cceec851
17:41:23 T:9140   DEBUG: DXVA - supports 'Intel VC-1 VLD'
17:41:23 T:9140   DEBUG: DXVA - supports 'VC-1 VLD 2010'
17:41:23 T:9140   DEBUG: DXVA - supports 'H.264 VLD, no FGT'
17:41:23 T:9140   DEBUG: DXVA - supports D79BE8DA-0cf1-4c81-b82a-69a4e236f43d
17:41:23 T:9140   DEBUG: DXVA - supports F9AACCBB-c2b6-4cfc-8779-5707b1760552
17:41:23 T:9140   DEBUG: DXVA - supports 705B9D82-76cf-49d6-b7e6-ac8872db013c
17:41:23 T:9140   DEBUG: DXVA - supports 9B8175D4-d670-4cf2-a9f0-fa56df71a1ae
17:41:23 T:9140   DEBUG: DXVA - supports 8EFA5926-bd9e-4b04-8b72-8f977dc44c36
17:41:23 T:9140   DEBUG: DXVA - supports 91CD2D6E-897b-4fa1-b0d7-51dc88010e0a
17:41:23 T:9140   DEBUG: DXVA - supports 442B942A-b4d9-4940-bc45-a882e5f919f3
17:41:23 T:9140   DEBUG: DXVA - supports 8C56EB1E-2b47-466f-8d33-7dbcd63f3df2
17:41:23 T:9140   DEBUG: DXVA - supports 'HEVC / H.265 variable-length decoder, main'
17:41:23 T:9140   DEBUG: DXVA - supports 75FC75F7-c589-4a07-a25b-72e03b0383b3
17:41:23 T:9140   DEBUG: DXVA - supports 'HEVC / H.265 variable-length decoder, main10'
17:41:23 T:9140   DEBUG: DXVA - supports 76988A52-df13-419a-8e64-ffcf4a336cf5
17:41:23 T:9140   DEBUG: DXVA - supports A74CCAE2-f466-45ae-86f5-ab8be8af8483
17:41:23 T:9140   DEBUG: DXVA - supports 'Windows Media Video 9 IDCT'
17:41:23 T:9140   DEBUG: DXVA - supports 'VC-1 IDCT'
17:41:23 T:9140   DEBUG: DXVA - supports 49761BEC-4b63-4349-a5ff-87ffdf088466
17:41:23 T:9140   DEBUG: DXVA - trying 'H.264 VLD, no FGT'
17:41:23 T:9140   DEBUG: DXVA - source requires 4 references
17:41:23 T:9140   DEBUG: DXVA - config 0: bitstream type 2
17:41:23 T:9140   DEBUG: DXVA - config 1: bitstream type 1
17:41:23 T:9140   DEBUG: DXVA - config 2: bitstream type 2, encrypted
17:41:23 T:9140   DEBUG: DXVA - config 3: bitstream type 1, encrypted
17:41:23 T:9140   DEBUG: DXVA - allocating 14 surfaces
17:41:23 T:9140   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(83000.000000, 0)
17:41:23 T:9140  NOTICE:  fps: 23.976024, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
17:41:23 T:9140   DEBUG: CDVDPlayerVideo::OutputPicture - change configuration. 1920x1080. framerate: 23.98. format: DXVA
17:41:23 T:9140  NOTICE: Display resolution ADJUST : 1920x1080@ 23.98 - Full Screen (132) (weight: 0.000)
17:41:23 T:9140  NOTICE: D3D: rendering method forced to DXVA processor
17:41:23 T:9140   DEBUG: DXVA::CProcessorHD::OpenProcessor - processor selected 7DD2D599-41db-4456-9395-8b3d18cedcae.
17:41:23 T:9140   DEBUG: CWinRenderer::SelectRenderMethod: Selected render method 3: DXVA
17:41:23 T:9140   DEBUG: CXBMCRenderManager::Configure - 5
17:41:23 T:6040   DEBUG: created video buffer 0
17:41:23 T:6040   DEBUG: created video buffer 1
17:41:23 T:6040   DEBUG: created video buffer 2
17:41:23 T:6040   DEBUG: created video buffer 3
17:41:23 T:6040   DEBUG: created video buffer 4
17:41:23 T:6040 WARNING: CWinRenderer::UpdateVideoFilter - chosen scaling method 1 is not supported by renderer
17:41:23 T:6040   DEBUG: CWinRenderer::CreateIntermediateRenderTarget: format 22
17:41:23 T:6040   DEBUG: CGUIInfoManager::SetCurrentMovie(smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv)
17:41:23 T:8976   DEBUG: CDVDPlayer::HandleMessages - player started 2
17:41:23 T:6040   DEBUG: CVideoDatabase::GetMovieId (smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv), query = select idMovie from movie where idFile=782
17:41:23 T:5628    INFO: CActiveAESink::OpenSink - initialize sink
17:41:23 T:6040   DEBUG: CVideoDatabase::GetMovieId (smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv), query = select idMovie from movie where idFile=782
17:41:23 T:6040   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
17:41:23 T:6040   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
17:41:23 T:6040   DEBUG: Activating window ID: 12005
17:41:23 T:6040   DEBUG: ------ Window Deinit (Home.xml) ------
17:41:23 T:6040   DEBUG: CWinSystemWin32::SetFullScreen (windowed fullscreen) on screen 0 with size 1920x1080, refresh 23.976023
17:41:23 T:5628   DEBUG: CActiveAESink::OpenSink - trying to open device WASAPI:default
17:41:23 T:5628    INFO: CAESinkWASAPI::InitializeExclusive: Format is Supported - will attempt to Initialize
17:41:23 T:5628    INFO: CAESinkWASAPI::InitializeExclusive: WASAPI Exclusive Mode Sink Initialized using: AE_FMT_S16NE, 192000, 8
17:41:23 T:5628   DEBUG: CActiveAESink::OpenSink - WASAPI Initialized:
17:41:23 T:5628   DEBUG:   Output Device : default
17:41:23 T:5628   DEBUG:   Sample Rate   : 192000
17:41:23 T:5628   DEBUG:   Sample Format : AE_FMT_S16NE
17:41:23 T:5628   DEBUG:   Channel Count : 8
17:41:23 T:5628   DEBUG:   Channel Layout: FL,FR,FC,LFE,BL,BR,SL,SR
17:41:23 T:5628   DEBUG:   Frames        : 9600
17:41:23 T:5628   DEBUG:   Frame Samples : 76800
17:41:23 T:5628   DEBUG:   Frame Size    : 16
17:41:23 T:8984   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
17:41:23 T:8976   DEBUG: Previous line repeats 1 times.
17:41:23 T:8976   DEBUG: CDVDPlayer::HandleMessages - player started 1
17:41:23 T:8976   DEBUG: CDVDPlayer::SetCaching - caching state 0
17:41:23 T:9140   DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
17:41:23 T:8316   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(10000.000000, 1)
17:41:23 T:8316  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
17:41:23 T:8316  NOTICE: Previous line repeats 8 times.
17:41:23 T:8316   DEBUG: CDVDPlayerAudio::HandleSyncError - average error -37823.588504 below threshold of 50000.000000
17:41:23 T:8316   DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:150627.097126, should be:112803.997370, error:-37823.099757
17:41:23 T:6040   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
17:41:23 T:6040   DEBUG: ------ Window Init (VideoFullScreen.xml) ------
17:41:23 T:6040   DEBUG: ------ Window Init (Pointer.xml) ------
17:41:23 T:6040   DEBUG: ------ Window Init (VideoOSD.xml) ------
17:41:24 T:8316   DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1113341.130944, should be:1134377.185986, error:21036.055042
17:41:28 T:6040   DEBUG: ------ Window Deinit (Pointer.xml) ------
17:41:28 T:9140   DEBUG: CPullupCorrection: detected pattern of length 1: 41708.33, frameduration: 41708.333333
17:41:31 T:6040   DEBUG: ------ Window Deinit (VideoOSD.xml) ------
17:41:42 T:6040   DEBUG: Keyboard: scancode: 0x17, sym: 0x0069, unicode: 0x0069, modifier: 0x0
17:41:42 T:6040   DEBUG: CInputManager::OnKey: i (0xf049) pressed, action is Info
17:41:44 T:6040   DEBUG: Keyboard: scancode: 0x17, sym: 0x0069, unicode: 0x0069, modifier: 0x0
17:41:44 T:6040   DEBUG: CInputManager::OnKey: i (0xf049) pressed, action is Info
17:41:53 T:4380   DEBUG: Thread JobWorker 4380 terminating (autodelete)
17:41:53 T:6396   DEBUG: Thread JobWorker 6396 terminating (autodelete)
17:41:53 T:6400   DEBUG: Thread JobWorker 6400 terminating (autodelete)
18:47:58 T:8316 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
18:47:58 T:9140 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:47:58 T:9140    INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 23.976024 fps
18:47:58 T:9140   DEBUG: CPullupCorrection: pattern lost on diff 208541.666667, number of losses 1
18:48:03 T:9140   DEBUG: CPullupCorrection: detected pattern of length 1: 41708.33, frameduration: 41708.333333
18:48:55 T:8976   DEBUG: CDVDPlayer::SetCaching - caching state 1
18:48:55 T:8976   DEBUG: CDVDPlayer::HandleMessages - player started 1
18:48:55 T:8976   DEBUG: CDVDPlayer::SetCaching - caching state 0
18:48:55 T:8316   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_EOF
18:48:55 T:9140    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
18:48:55 T:9140   DEBUG: CPullupCorrection: pattern lost on diff -57098416.666884, number of losses 2
18:48:55 T:8976   DEBUG: CDVDPlayer::HandleMessages - player started 2
18:48:55 T:8976    INFO: CDVDPlayer::Process - eof reading from demuxer
18:48:55 T:8976  NOTICE: CDVDPlayer::OnExit()
18:48:55 T:8976  NOTICE: DVDPlayer: eof, waiting for queues to empty
18:48:55 T:8976  NOTICE: Closing stream player 1
18:48:55 T:8976  NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
18:48:55 T:8316   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
18:48:55 T:8976  NOTICE: Waiting for audio thread to exit
18:48:55 T:8316   DEBUG: CDVDPlayerAudio::Process - Abort received, exiting thread
18:48:55 T:8316  NOTICE: thread end: CDVDPlayerAudio::OnExit()
18:48:55 T:8976  NOTICE: Closing audio device
18:48:55 T:8316   DEBUG: Thread DVDPlayerAudio 8316 terminating
18:48:55 T:8976  NOTICE: Deleting audio codec
18:48:55 T:8984   DEBUG: CActiveAE::DiscardStream - audio stream deleted
18:48:55 T:8976  NOTICE: Closing stream player 2
18:48:55 T:8976  NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
18:48:55 T:8984   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:48:55 T:9140   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
18:48:55 T:8976  NOTICE: waiting for video thread to exit
18:48:55 T:8984   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:48:55 T:9140   ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
18:48:55 T:9140  NOTICE: thread end: video_thread
18:48:55 T:8976  NOTICE: deleting video codec
18:48:55 T:9140   DEBUG: Thread DVDPlayerVideo 9140 terminating
18:48:55 T:8976   DEBUG: DXVA::CDecoder::~CDecoder - destructing decoder, 88201664
18:48:55 T:8976  NOTICE: DXVA::CDecoder::Close - closing decoder
18:48:55 T:8976  NOTICE: DXVA::Close - closing decoder context
18:48:55 T:8976  NOTICE: Closing stream player 3
18:48:55 T:8976   DEBUG: CApplication::OnPlayBackEnded: play state was 2, starting 0
18:48:55 T:8976   DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
18:48:55 T:8976   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
18:48:55 T:8976   DEBUG: Thread DVDPlayer 8976 terminating
18:48:55 T:6040   DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
18:48:55 T:6040   DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
18:48:55 T:6040   DEBUG: CWinSystemWin32::SetFullScreen (windowed fullscreen) on screen 0 with size 1920x1080, refresh 59.940056
18:48:55 T:5628    INFO: CActiveAESink::OpenSink - initialize sink
18:48:55 T:5628   DEBUG: CActiveAESink::OpenSink - trying to open device WASAPI:default
18:48:55 T:5628    INFO: CAESinkWASAPI::InitializeExclusive: WASAPI Exclusive Mode Sink Initialized using: AE_FMT_S24NE4MSB, 44100, 2
18:48:55 T:5628   DEBUG: CActiveAESink::OpenSink - WASAPI Initialized:
18:48:55 T:5628   DEBUG:   Output Device : default
18:48:55 T:5628   DEBUG:   Sample Rate   : 44100
18:48:55 T:5628   DEBUG:   Sample Format : AE_FMT_S24NE4MSB
18:48:55 T:5628   DEBUG:   Channel Count : 2
18:48:55 T:5628   DEBUG:   Channel Layout: FL,FR
18:48:55 T:5628   DEBUG:   Frames        : 2208
18:48:55 T:5628   DEBUG:   Frame Samples : 4416
18:48:55 T:5628   DEBUG:   Frame Size    : 8
18:48:55 T:8984   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:48:55 T:6040   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
18:48:55 T:6040   DEBUG: CGUIWindowManager::PreviousWindow: Activate new
18:48:55 T:6040   DEBUG: ------ Window Init (Home.xml) ------
18:48:55 T:8252  NOTICE: Thread JobWorker start, auto delete: true
18:48:55 T:8252   DEBUG: CSaveFileStateJob::DoWork - Saving file state for video item smb://DL4100/Videos/HD/Films/MakeMKV/The King and I (1956).mkv
18:48:56 T:8252   DEBUG: CAnnouncementManager - Announcement: OnUpdate from xbmc
18:48:56 T:8252   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnUpdate
18:48:56 T:6040  NOTICE: CDVDPlayer::CloseFile()
18:48:56 T:6040  NOTICE: DVDPlayer: waiting for threads to exit
18:48:56 T:6040  NOTICE: DVDPlayer: finished waiting
18:48:56 T:6040   DEBUG: DXVA::CSurfaceContext::~CSurfaceContext - destructing surface context
18:48:56 T:6040  NOTICE: CDVDPlayer::CloseFile()
18:48:56 T:6040  NOTICE: DVDPlayer: waiting for threads to exit
18:48:56 T:6040  NOTICE: DVDPlayer: finished waiting
18:49:26 T:8252   DEBUG: Thread JobWorker 8252 terminating (autodelete)

Any ideas please what to try?

Also, can you leave debugging logging on and not have the on screen display in top left?

Many thanks.
Find
Reply
Automan
Junior Member
Posts: 17
#2
2015-12-26, 13:46
I have turned off full logging due to the annoying on screen message Sad

Two more events today

10:07:34 T:8840 NOTICE: D3D: rendering method forced to DXVA processor
10:07:34 T:7608 WARNING: CWinRenderer::UpdateVideoFilter - chosen scaling method 1 is not supported by renderer
10:07:34 T:2332 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
10:23:07 T:2332 NOTICE: Previous line repeats 8 times.
10:23:07 T:2332 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
10:23:07 T:8840 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available

10:58:23 T:6548 NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1920x1080)
10:58:23 T:6548 NOTICE: fps: 23.976024, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
10:58:23 T:6548 NOTICE: Display resolution ADJUST : 1920x1080@ 23.98 - Full Screen (132) (weight: 0.000)
10:58:23 T:6548 NOTICE: D3D: rendering method forced to DXVA processor
10:58:23 T:7608 WARNING: CWinRenderer::UpdateVideoFilter - chosen scaling method 1 is not supported by renderer
10:58:23 T:7556 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
11:30:36 T:7556 NOTICE: Previous line repeats 7 times.
11:30:36 T:7556 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
11:30:36 T:6548 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
11:31:36 T:2468 NOTICE: CDVDPlayer::OnExit()

No WiFi involved and I can copy files to and from my NAS at over 100Mb/sec

Any ideas anyone what to try?

One last thing I have noted is that the sound format information is nearly always wrong when you press "I"

It often claims DTS-HD Master Audio 7.1 sound when the format is actually 5.1
Pressing "O" thells me the current item is DTS-HD MA, 48000Hz, 6.1, fltp, 1536 kb/s, this item has 6.1 sound as indicated by my Sony Amp

My Android player running an earlier version displays the correct information but cant of course play them in that format.

EDIT:

Created advancedsettings.xml

<advancedsettings>
<loglevel>1</loglevel>
</advancedsettings>

Added, so debug logging now on without the on screen message.
Find
Reply
Automan
Junior Member
Posts: 17
#3
2015-12-27, 16:38
Still a very random problem,
Watched three movies with no problems then a freeze 1hr15m into a movie.

Code:
13:10:50 T:8676  NOTICE: Display resolution ADJUST : 1920x1080@ 23.98 - Full Screen (132) (weight: 0.000)
13:10:50 T:8676  NOTICE: D3D: rendering method forced to DXVA processor
13:10:50 T:5728 WARNING: CWinRenderer::UpdateVideoFilter - chosen scaling method 1 is not supported by renderer
13:10:50 T:9660  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
14:26:51 T:9660  NOTICE: Previous line repeats 9 times.
14:26:51 T:9660 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
14:26:51 T:8676 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
14:27:52 T:9660  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 10
14:27:52 T:9660  NOTICE: Previous line repeats 1 times.
14:27:52 T:9660 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
14:27:52 T:7612  NOTICE: CDVDPlayer::OnExit()
14:27:52 T:7612  NOTICE: DVDPlayer: eof, waiting for queues to empty
14:27:52 T:7612  NOTICE: Closing stream player 1
14:27:52 T:7612  NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
14:27:52 T:7612  NOTICE: Waiting for audio thread to exit
14:27:52 T:9660  NOTICE: thread end: CDVDPlayerAudio::OnExit()
14:27:52 T:7612  NOTICE: Closing audio device
14:27:52 T:7612  NOTICE: Deleting audio codec
14:27:52 T:7612  NOTICE: Closing stream player 2
14:27:52 T:7612  NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
14:27:52 T:7612  NOTICE: waiting for video thread to exit
14:27:52 T:8676   ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
14:27:52 T:8676  NOTICE: thread end: video_thread
14:27:52 T:7612  NOTICE: deleting video codec
14:27:52 T:7612  NOTICE: DXVA::CDecoder::Close - closing decoder
14:27:52 T:7612  NOTICE: DXVA::Close - closing decoder context
14:27:52 T:7612  NOTICE: Closing stream player 3
14:27:53 T:8688  NOTICE: Thread BackgroundLoader start, auto delete: false
14:27:53 T:8464  NOTICE: Thread JobWorker start, auto delete: true
14:27:53 T:5728  NOTICE: CDVDPlayer::CloseFile()
14:27:53 T:5728  NOTICE: DVDPlayer: waiting for threads to exit
14:27:53 T:5728  NOTICE: DVDPlayer: finished waiting
14:27:53 T:5728  NOTICE: CDVDPlayer::CloseFile()
14:27:53 T:5728  NOTICE: DVDPlayer: waiting for threads to exit
14:27:53 T:5728  NOTICE: DVDPlayer: finished waiting
14:27:58 T:5728  NOTICE: DVDPlayer: Opening: smb://DL4100/Videos/HD/Films/MakeMKV/Tremors 5 Bloodlines (2015).mkv
14:27:58 T:5728 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
14:27:58 T:3980  NOTICE: Thread DVDPlayer start, auto delete: false
14:27:58 T:3980  NOTICE: Creating InputStream
14:28:01 T:3980  NOTICE: Creating Demuxer
14:28:01 T:3980  NOTICE: Opening stream: 0 source: 256
14:28:01 T:3980  NOTICE: Creating video codec with codec id: 28
14:28:01 T:3980  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
14:28:01 T:3980  NOTICE: Creating video thread
14:28:01 T:3980  NOTICE: Opening stream: 1 source: 256
14:28:01 T:3980  NOTICE: Finding audio codec for: 86020
14:28:01 T:3980  NOTICE: Creating audio thread
14:28:01 T:7344  NOTICE: Thread DVDPlayerVideo start, auto delete: false
14:28:01 T:7344  NOTICE: running thread: video_thread
14:28:01 T:3980  NOTICE: Opening stream: 2 source: 256
14:28:01 T:9572  NOTICE: Thread DVDPlayerAudio start, auto delete: false
14:28:01 T:9572  NOTICE: running thread: CDVDPlayerAudio::Process()

Any thoughts please?
Find
Reply
Automan
Junior Member
Posts: 17
#4
2015-12-27, 19:10
Tried a BIOS update and new Intel RAID and Video drivers (dated 21/12/2015) but no improvement Sad

I also noted I had the xml for debugging in the wrong folder so here are the lines from just before the picture pause.

Code:
16:25:13 T:3492   DEBUG: Thread RemoteControl 3492 terminating
17:04:06 T:6396 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
17:04:06 T:1444 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
17:04:07 T:1444    INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 29.970030 fps
17:04:07 T:1444   DEBUG: CPullupCorrection: pattern lost on diff 166833.333333, number of losses 1
17:04:10 T:1444   DEBUG: CPullupCorrection: detected pattern of length 1: 33366.67, frameduration: 33366.666667
17:04:22 T:8172   DEBUG: Keyboard: scancode: 0x17, sym: 0x0069, unicode: 0x0069, modifier: 0x0
17:04:22 T:8172   DEBUG: CInputManager::OnKey: i (0xf049) pressed, action is Info
17:04:27 T:8172   DEBUG: Keyboard: scancode: 0x17, sym: 0x0069, unicode: 0x0069, modifier: 0x0
17:04:27 T:8172   DEBUG: CInputManager::OnKey: i (0xf049) pressed, action is Info
17:04:28 T:8172   DEBUG: Keyboard: scancode: 0x18, sym: 0x006f, unicode: 0x006f, modifier: 0x0
17:04:28 T:8172   DEBUG: CInputManager::OnKey: o (0xf04f) pressed, action is CodecInfo
17:05:02 T:4748   DEBUG: CDVDPlayer::SetCaching - caching state 1
17:05:02 T:4748   DEBUG: CDVDPlayer::HandleMessages - player started 1
17:05:02 T:4748   DEBUG: CDVDPlayer::SetCaching - caching state 0
17:05:02 T:6396   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_EOF
17:05:02 T:1444    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
17:05:02 T:1444   DEBUG: CPullupCorrection: pattern lost on diff -55421399.999736, number of losses 2
17:05:02 T:4748   DEBUG: CDVDPlayer::HandleMessages - player started 2
17:05:02 T:4748    INFO: CDVDPlayer::Process - eof reading from demuxer
17:05:02 T:4748  NOTICE: CDVDPlayer::OnExit()
17:05:02 T:4748  NOTICE: DVDPlayer: eof, waiting for queues to empty
17:05:02 T:4748  NOTICE: Closing stream player 1
17:05:02 T:4748  NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
17:05:02 T:6396   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
17:05:02 T:4748  NOTICE: Waiting for audio thread to exit
17:05:02 T:6396   DEBUG: CDVDPlayerAudio::Process - Abort received, exiting thread
17:05:02 T:6396  NOTICE: thread end: CDVDPlayerAudio::OnExit()
17:05:02 T:6396   DEBUG: Thread DVDPlayerAudio 6396 terminating
17:05:02 T:4748  NOTICE: Closing audio device
17:05:02 T:4748  NOTICE: Deleting audio codec
17:05:02 T:3828   DEBUG: CActiveAE::DiscardStream - audio stream deleted
17:05:02 T:4748  NOTICE: Closing stream player 2
17:05:02 T:4748  NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
17:05:02 T:1444   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
17:05:02 T:4748  NOTICE: waiting for video thread to exit
17:05:02 T:1444   ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
17:05:02 T:1444  NOTICE: thread end: video_thread
17:05:02 T:4748  NOTICE: deleting video codec
17:05:02 T:1444   DEBUG: Thread DVDPlayerVideo 1444 terminating
17:05:02 T:3828   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
17:05:02 T:4748   DEBUG: Previous line repeats 1 times.
17:05:02 T:4748   DEBUG: DXVA::CDecoder::~CDecoder - destructing decoder, 181764744
17:05:02 T:4748  NOTICE: DXVA::CDecoder::Close - closing decoder
17:05:02 T:4748  NOTICE: DXVA::Close - closing decoder context
17:05:02 T:4748  NOTICE: Closing stream player 3
17:05:02 T:4748   DEBUG: CApplication::OnPlayBackEnded: play state was 2, starting 0
17:05:02 T:4748   DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
17:05:02 T:4748   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
17:05:02 T:4748   DEBUG: Thread DVDPlayer 4748 terminating
17:05:02 T:8172   DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
17:05:02 T:8172   DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
17:05:02 T:8172   DEBUG: CGUIWindowManager::PreviousWindow: Activate new
17:05:02 T:8172   DEBUG: ------ Window Init (MyVideoNav.xml) ------
17:05:02 T:8172   DEBUG: CGUIMediaWindow::GetDirectory (videodb://tvshows/titles/15/-2/?tvshowid=15)
17:05:02 T:8172   DEBUG:   ParentPath = [videodb://tvshows/titles/15/-2/?tvshowid=15]
17:05:02 T:8172   DEBUG: CVideoDatabase::RunQuery took 3 ms for 5 items query: select * from episode_view  WHERE episode_view.idShow = 15
17:05:02 T:8172   DEBUG: CVideoDatabase::RunQuery took 11 ms for 0 items query: select * from movie_view join movielinktvshow on movielinktvshow.idMovie=movie_view.idMovie WHERE movielinktvshow.idShow = 15
17:05:02 T:8172   DEBUG: WindowVideoNav::GetDirectory
17:05:02 T:5804  NOTICE: Thread BackgroundLoader start, auto delete: false
17:05:02 T:5804   DEBUG: Thread BackgroundLoader 5804 terminating
17:05:02 T:8172  NOTICE: CDVDPlayer::CloseFile()
17:05:02 T:8172  NOTICE: DVDPlayer: waiting for threads to exit
17:05:02 T:8172  NOTICE: DVDPlayer: finished waiting
17:05:02 T:8172   DEBUG: DXVA::CSurfaceContext::~CSurfaceContext - destructing surface context
17:05:02 T:8172  NOTICE: CDVDPlayer::CloseFile()
17:05:02 T:8172  NOTICE: DVDPlayer: waiting for threads to exit
17:05:02 T:8172  NOTICE: DVDPlayer: finished waiting
17:05:02 T:8172   DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib.dll)
17:05:02 T:6796  NOTICE: Thread JobWorker start, auto delete: true
17:05:02 T:6796   DEBUG: CSaveFileStateJob::DoWork - Saving file state for video item smb://DL4100/Videos/HD/TV/Torchwood/Season 1/1x02.mkv
17:05:02 T:2516    INFO: CActiveAESink::OpenSink - initialize sink
17:05:02 T:6796   DEBUG: CSaveFileStateJob::DoWork - Marking video item smb://DL4100/Videos/HD/TV/Torchwood/Season 1/1x02.mkv as watched
17:05:02 T:6796   DEBUG: CAnnouncementManager - Announcement: OnUpdate from xbmc
17:05:02 T:6796   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnUpdate
17:05:02 T:2516   DEBUG: CActiveAESink::OpenSink - trying to open device WASAPI:default
17:05:02 T:2516    INFO: CAESinkWASAPI::InitializeExclusive: WASAPI Exclusive Mode Sink Initialized using: AE_FMT_S24NE4MSB, 44100, 2
17:05:02 T:2516   DEBUG: CActiveAESink::OpenSink - WASAPI Initialized:
17:05:02 T:2516   DEBUG:   Output Device : default
17:05:02 T:2516   DEBUG:   Sample Rate   : 44100
17:05:02 T:2516   DEBUG:   Sample Format : AE_FMT_S24NE4MSB
17:05:02 T:2516   DEBUG:   Channel Count : 2
17:05:02 T:2516   DEBUG:   Channel Layout: FL,FR
17:05:02 T:2516   DEBUG:   Frames        : 2208
17:05:02 T:2516   DEBUG:   Frame Samples : 4416
17:05:02 T:2516   DEBUG:   Frame Size    : 8
17:05:02 T:3828   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
17:05:32 T:6796   DEBUG: Thread JobWorker 6796 terminating (autodelete)
Find
Reply
Automan
Junior Member
Posts: 17
#5
2015-12-28, 12:05
No progress or alas any help so far so I went for the ultimate (wrong time of year I guess).

Reinstalled Windows 10 from Microsoft USB stick image (no acer extras).

Same problem alas still persists Sad

Any ideas? Anyone?
Find
Reply
Automan
Junior Member
Posts: 17
#6
2015-12-28, 23:33
Tried playing with settings in PC BIOS relating to video and setting in video driver but with no luck Sad

I have debugging on and have used the upload add-on to post the latest log to http://xbmclogs.com/paozzngrp

Problem starts at line 2810

WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available

Any thoughts please?
Find
Reply
Automan
Junior Member
Posts: 17
#7
2015-12-29, 17:31
I have made another change to the cache settings in Kodi and so far, all has been well (fingers crossed).

I added

<advancedsettings>
<network>
<buffermode>1</buffermode>
<cachemembuffersize>0</cachemembuffersize>
<readbufferfactor>30</readbufferfactor>
</network>
</advancedsettings>

to advancedsettings.xml which makes it download the complete recording at about 5Gb per minute to the local SSD and plays that.

It seems to work and if this is the case I guess there is an issue with the Kodi smb and Windows 10.

As an added bonus it saves electricity as my WD NAS can now go to sleep once the complete title has copied over (small lag alas while it spins up to watch another recording).

http://kodi.wiki/view/HOW-TO:Modify_the_video_cache
Find
Reply
Automan
Junior Member
Posts: 17
#8
2016-01-07, 11:51
An update to my issues

Generally all works well with the above setting, effectively making Kodi copy the entire item to the local drive and playing that cache copy.

Looking in other threads I see this is not good for solid state drives so I have been trying other settings all of which bring back the problem.

Reducing the cachemembuffers to a low value e.g. 5 causes only about a third of the item to be copied locally and playback stops when it reaches the end of that.

I have noted however, at the point the picture freezes, if I press Ctrl S to catch a screen dump, the video seems to reverse playback a bit and more cache is downloaded again (my screenshot folder is on the same smb host - any connection?).

I have turned logging on and this is the latest log (tried running the latest Kodi, but no change)

http://xbmclogs.com/pi7pyqyoc

My desktop Windows 10 PC does exactly the same

Log attached here

http://xbmclogs.com/pf6t76cc4


Is it just me or are there issues with the SMB and Windows 10?

My Android MINIX box seems okay and so far my Windows 7 laptop has been okay (will do some more tests)
Find
Reply
Automan
Junior Member
Posts: 17
#9
2016-01-07, 19:30
Another idea Smile

My WD DL4100 NAS supports NFS

So I have given my NAS a static IP address and enabled NFS for my Video share.

Fresh, clean install of Kodi with no extra xml files.

So far it seems to work 100%

If so, I guess the issue is with the SMB component?
Find
Reply

Home
Search
Help
Logout Mark Read Team Forum Stats Members Help
[FIXED] Kodi 15.2 Random Playback Freezes And Return To Menu0