2013-09-11, 06:34
Bad title... hard to summarize my issue.
I have an AVI file that plays fine, when the actual file is put into the library on a local disk source, or SMB source.
If I take that same file, put it on a http server (apache 2.2) and create a .strm file that points to it (it's still on the same machine) it won't play it.
About 1/3 of my video files are this way. My only guess is maybe it's the way the video is encoded?
Now you may be wondering why the hell am I doing this... so if you care, read on:
I am running XBMC on my android phone (Galaxy Note 2) and two HTPCs. I wanted a way to keep my library in sync when I'm on the go on my phone. I have a decently fast upload so even when I'm at a friends house, or on 4G my home upload bandwidth can stream me a HD file with no buffering or issues. Low latency too. I am of course running a SQL server to keep the library synced, and this is working flawlessly.
I originally tried to do this all with SMB shares. I would VPN into my home network on my phone, load up XBMC and away I went. Only issue is SMB over internet is very slow, due to windows limiting packet size. I was only getting 100KB/sec (800kbps roughly).
So I was stuck. Then I had the idea to put my actual movies/tv shows on the Apache HTTP server. So XBMC's sync'ed library on HTPCs and Android do not see the actual local files, but instead sees a STRM file with NFO file that points to the "website" where the movie is stored. It's on a local server, using a DNS redirect. So the STRM file would be http://myname.redirectsite.com/Movies/Mo...vieABC.avi
Wiped the library clean, manually created all the STRM files, and re scanned the library. Since the NFO files are present I didn't have to scrub anything.
Now all my movies show up on my PC and my phone, with no issue... or so I thought. I started going down the list testing them. My phone is on 4G internet, VPN'ed into my home network. Library loads up fine, first 4 or 5 movies play perfect. About 2-3 seconds of buffering and then they play just fine.
Get down the list and I start having movies that won't play. Re-Check and Triple check the STRM files, all valid URLs. To rule out the file I added it to the library as a local source, and even as a network share source. It plays fine on XBMC both locally and by SMB share. Only when I try and access the movie via http does it fail.
I have of course enabled debugging and posted the relevant log info below. Thank you in advance for any assistance.
The acutal URL has been changed, but please take my word that I have gone over each STRM file atleast 3 times ensuring the URL is exactly correct. I have a PHP "file directory" script running on the web server. I right click -> Copy link location on each movie file. Verified the URL is correct by pasting it directly from the STRM file to the address bar of my browser and it opens.
Now as a comparison here's a log from one set up the EXACT same way, that plays fine:
I have an AVI file that plays fine, when the actual file is put into the library on a local disk source, or SMB source.
If I take that same file, put it on a http server (apache 2.2) and create a .strm file that points to it (it's still on the same machine) it won't play it.
About 1/3 of my video files are this way. My only guess is maybe it's the way the video is encoded?
Now you may be wondering why the hell am I doing this... so if you care, read on:
I am running XBMC on my android phone (Galaxy Note 2) and two HTPCs. I wanted a way to keep my library in sync when I'm on the go on my phone. I have a decently fast upload so even when I'm at a friends house, or on 4G my home upload bandwidth can stream me a HD file with no buffering or issues. Low latency too. I am of course running a SQL server to keep the library synced, and this is working flawlessly.
I originally tried to do this all with SMB shares. I would VPN into my home network on my phone, load up XBMC and away I went. Only issue is SMB over internet is very slow, due to windows limiting packet size. I was only getting 100KB/sec (800kbps roughly).
So I was stuck. Then I had the idea to put my actual movies/tv shows on the Apache HTTP server. So XBMC's sync'ed library on HTPCs and Android do not see the actual local files, but instead sees a STRM file with NFO file that points to the "website" where the movie is stored. It's on a local server, using a DNS redirect. So the STRM file would be http://myname.redirectsite.com/Movies/Mo...vieABC.avi
Wiped the library clean, manually created all the STRM files, and re scanned the library. Since the NFO files are present I didn't have to scrub anything.
Now all my movies show up on my PC and my phone, with no issue... or so I thought. I started going down the list testing them. My phone is on 4G internet, VPN'ed into my home network. Library loads up fine, first 4 or 5 movies play perfect. About 2-3 seconds of buffering and then they play just fine.
Get down the list and I start having movies that won't play. Re-Check and Triple check the STRM files, all valid URLs. To rule out the file I added it to the library as a local source, and even as a network share source. It plays fine on XBMC both locally and by SMB share. Only when I try and access the movie via http does it fail.
I have of course enabled debugging and posted the relevant log info below. Thank you in advance for any assistance.
The acutal URL has been changed, but please take my word that I have gone over each STRM file atleast 3 times ensuring the URL is exactly correct. I have a PHP "file directory" script running on the web server. I right click -> Copy link location on each movie file. Verified the URL is correct by pasting it directly from the STRM file to the address bar of my browser and it opens.
Quote:00:27:40 T:2220 DEBUG: ------ Window Init (MyVideoNav.xml) ------
00:27:40 T:2220 DEBUG: CGUIMediaWindow::GetDirectory (videodb://1/2/)
00:27:40 T:2220 DEBUG: ParentPath = [videodb://1/2/]
00:27:40 T:2220 DEBUG: CVideoDatabase::RunQuery took 4 ms for 19 items query: select * from movieview
00:27:40 T:2124 NOTICE: Thread Background Loader start, auto delete: false
00:27:40 T:2124 DEBUG: Thread Background Loader 2124 terminating
00:27:40 T:2220 DEBUG: CApplication::ExecuteXBMCAction : Translating ClearProperty(BrowseActors,home)
00:27:40 T:2220 DEBUG: CApplication::ExecuteXBMCAction : To ClearProperty(BrowseActors,home)
00:27:41 T:2220 DEBUG: Keyboard: scancode: 50, sym: 0112, unicode: 0000, modifier: 0
00:27:41 T:2220 DEBUG: CApplication::OnKey: down (f081) pressed, action is Down
00:27:44 T:2220 DEBUG: Keyboard: scancode: 1c, sym: 000d, unicode: 000d, modifier: 0
00:27:44 T:2220 DEBUG: CApplication::OnKey: return (f00d) pressed, action is Select
00:27:44 T:2220 DEBUG: CGUIWindowVideoBase::OnPlayMedia smb://192.168.0.10/MovieStreams/The Adjustment Bureau 2011/The Adjustment Bureau 2011.strm
00:27:44 T:2220 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
00:27:44 T:2220 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
00:27:44 T:2220 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
00:27:44 T:2220 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
00:27:44 T:2220 DEBUG: CAnnouncementManager - Announcement: OnRemove from xbmc
00:27:44 T:2220 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnRemove
00:27:44 T:2220 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
00:27:44 T:2220 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers(http://myname.redirectsite.net/Movies/The%20Adjustment%20Bureau%202011/The%20Adjustment%20Bureau%202011.avi)
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
00:27:44 T:2220 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
00:27:44 T:2220 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
00:27:44 T:2220 NOTICE: DVDPlayer: Opening: http://myname.redirectsite.net/Movies/The%20Adjustment%20Bureau%202011/The%20Adjustment%20Bureau%202011.avi
00:27:44 T:2220 WARNING: CDVDMessageQueue(player):ut MSGQ_NOT_INITIALIZED
00:27:44 T:2220 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
00:27:44 T:2220 DEBUG: DXVA - cheking samples array size using 842094158 render target
00:27:44 T:2220 DEBUG: DXVA - cheking samples array size using 842094169 render target
00:27:44 T:2792 NOTICE: Thread CDVDPlayer start, auto delete: false
00:27:44 T:2792 NOTICE: Creating InputStream
00:27:44 T:2792 WARNING: XFILE::CFileFactory::CreateLoader - Unsupported protocol(http) in http://myname.redirectsite.net/Movies/The%20Adjustment%20Bureau%202011/The%20Adjustment%20Bureau%202011.avi
00:27:44 T:2792 ERROR: CDVDPlayer::OpenInputStream - error opening [http://myname.redirectsite.net/Movies/The%20Adjustment%20Bureau%202011/The%20Adjustment%20Bureau%202011.avi]
00:27:44 T:2792 NOTICE: CDVDPlayer::OnExit()
00:27:44 T:2792 NOTICE: CDVDPlayer::OnExit() deleting input stream
00:27:44 T:2792 DEBUG: Thread CDVDPlayer 2792 terminating
00:27:44 T:2220 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
00:27:44 T:2220 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
00:27:44 T:2220 ERROR: Playlist Player: skipping unplayable item: 0, path [http://myname.redirectsite.net/Movies/The%20Adjustment%20Bureau%202011/The%20Adjustment%20Bureau%202011.avi]
00:27:44 T:3360 NOTICE: Thread Background Loader start, auto delete: false
00:27:44 T:3360 DEBUG: Thread Background Loader 3360 terminating
00:27:44 T:2220 NOTICE: CDVDPlayer::CloseFile()
00:27:44 T:2220 WARNING: CDVDMessageQueue(player):
00:27:44 T:2220 NOTICE: DVDPlayer: waiting for threads to exit
00:27:44 T:2220 NOTICE: DVDPlayer: finished waiting
00:27:44 T:2220 DEBUG: ------ Window Init (DialogKaiToast.xml) ------
Now as a comparison here's a log from one set up the EXACT same way, that plays fine:
Quote:00:30:35 T:2948 DEBUG: ------ Window Init (MyVideoNav.xml) ------
00:30:35 T:2948 INFO: Loading skin file: MyVideoNav.xml, load type: KEEP_IN_MEMORY
00:30:38 T:2948 DEBUG: CGUIMediaWindow::GetDirectory (videodb://1/2/)
00:30:38 T:2948 DEBUG: ParentPath = [videodb://1/2/]
00:30:38 T:2948 DEBUG: CVideoDatabase::RunQuery took 5 ms for 19 items query: select * from movieview
00:30:38 T:1972 NOTICE: Thread Background Loader start, auto delete: false
00:30:38 T:1972 DEBUG: Thread Background Loader 1972 terminating
00:30:38 T:2852 NOTICE: Thread Background Loader start, auto delete: false
00:30:38 T:2852 DEBUG: Thread Background Loader 2852 terminating
00:30:38 T:2948 DEBUG: CApplication::ExecuteXBMCAction : Translating ClearProperty(BrowseActors,home)
00:30:38 T:2948 DEBUG: CApplication::ExecuteXBMCAction : To ClearProperty(BrowseActors,home)
00:30:39 T:3288 INFO: Scriptresult: Success
00:30:39 T:3288 INFO: Python script stopped
00:30:39 T:3288 DEBUG: Thread XBPyThread 3288 terminating
00:30:39 T:2948 DEBUG: waiting for python thread 9 (C:\Documents and Settings\Owner\Application Data\XBMC\addons\weather.wunderground\default.py) to stop
00:30:39 T:2948 DEBUG: python thread 9 (C:\Documents and Settings\Owner\Application Data\XBMC\addons\weather.wunderground\default.py) destructed
00:30:39 T:852 DEBUG: CZipManager::GetZipList - Processing zip://special%3a%2f%2fxbmc%2fmedia%2fweather.zip/
00:30:39 T:1396 DEBUG: CImageLoader:oWork - took 108 ms to load special://skin/backgrounds/movies/home_movies.jpg
00:30:39 T:852 DEBUG: POParser: PO file has Win Style Line Endings. Converted in memory to Linux LF for file: special://xbmc/language/English/strings.po
00:30:39 T:852 DEBUG: POParser: loaded 109 weather tokens
00:30:53 T:2948 DEBUG: Keyboard: scancode: 50, sym: 0112, unicode: 0000, modifier: 0
00:30:53 T:2948 DEBUG: CApplication::OnKey: down (f081) pressed, action is Down
00:30:54 T:2948 DEBUG: Keyboard: scancode: 50, sym: 0112, unicode: 0000, modifier: 0
00:30:54 T:2948 DEBUG: CApplication::OnKey: down (f081) pressed, action is Down
00:30:55 T:2948 DEBUG: Keyboard: scancode: 1c, sym: 000d, unicode: 000d, modifier: 0
00:30:55 T:2948 DEBUG: CApplication::OnKey: return (f00d) pressed, action is Select
00:30:55 T:2948 DEBUG: CGUIWindowVideoBase::OnPlayMedia smb://192.168.0.10/MovieStreams/Avatar/avatar.strm
00:30:55 T:2948 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
00:30:55 T:2948 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
00:30:55 T:2948 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
00:30:55 T:2948 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
00:30:55 T:2948 DEBUG: CAnnouncementManager - Announcement: OnRemove from xbmc
00:30:55 T:2948 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnRemove
00:30:55 T:2948 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
00:30:55 T:2948 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
00:30:55 T:2948 INFO: XCURL:
00:30:55 T:2948 DEBUG: CCurlFile::GetMimeType - http://myname.redirectsite.net/Movies/Av...202009.avi -> video/x-msvideo
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers(http://myname.redirectsite.net/Movies/Av...202009.avi)
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: streams
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: aacp/sdp
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mp2
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
00:30:55 T:2948 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
00:30:55 T:2948 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
00:30:55 T:2948 NOTICE: DVDPlayer: Opening: http://myname.redirectsite.net/Movies/Av...202009.avi
00:30:55 T:2948 WARNING: CDVDMessageQueue(player):
00:30:55 T:2948 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
00:30:55 T:2948 DEBUG: DXVA - cheking samples array size using 842094158 render target
00:30:55 T:2948 DEBUG: DXVA - cheking samples array size using 842094169 render target
00:30:55 T:3700 NOTICE: Thread CDVDPlayer start, auto delete: false
00:30:55 T:3700 NOTICE: Creating InputStream
00:30:55 T:3700 DEBUG: CFileCache::Open - opening <Movies/Avatar%202009/Avatar%202009.avi> using cache
00:30:55 T:3700 DEBUG: CurlFile::Open(0509E098) http://myname.redirectsite.net/Movies/Av...202009.avi
00:30:55 T:3700 NOTICE: Creating Demuxer
00:30:55 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avutil-51.dll)
00:30:55 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avcodec-53.dll)
00:30:55 T:2948 DEBUG: ------ Window Init (DialogBusy.xml) ------
00:30:55 T:3820 NOTICE: Thread CFileCache start, auto delete: false
00:30:55 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avformat-53.dll)
00:30:55 T:3700 DEBUG: CDVDDemuxFFmpeg::Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
00:30:55 T:3820 DEBUG: XFILE::CFileCache:
00:30:55 T:3820 INFO: XCURL:
00:30:55 T:3700 DEBUG: XFILE::CFileCache::Seek - waiting for position 1177662193.
00:30:55 T:3820 INFO: CFileCache:
00:30:55 T:3700 DEBUG: CDVDDemuxFFmpeg::Open - avformat_find_stream_info starting
00:30:55 T:3820 DEBUG: XFILE::CFileCache:
00:30:55 T:3700 DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info finished
00:30:55 T:3700 INFO: ffmpeg[E74]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'http://myname.redirectsite.net/Movies/Avatar%202009/Avatar%202009.avi':
00:30:55 T:3700 INFO: ffmpeg[E74]: Metadata:
00:30:55 T:3700 INFO: ffmpeg[E74]: major_brand : isom
00:30:55 T:3700 INFO: ffmpeg[E74]: minor_version : 1
00:30:55 T:3700 INFO: ffmpeg[E74]: compatible_brands: isomavc1
00:30:55 T:3700 INFO: ffmpeg[E74]: creation_time : 2012-02-03 14:29:20
00:30:55 T:3700 INFO: ffmpeg[E74]: Duration: 02:58:09.67, start: 0.000000, bitrate: 881 kb/s
00:30:55 T:3700 INFO: ffmpeg[E74]: Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 814 kb/s, 23.98 fps, 23.98 tbr, 96k tbn, 47.95 tbc
00:30:55 T:3700 INFO: ffmpeg[E74]: Metadata:
00:30:55 T:3700 INFO: ffmpeg[E74]: creation_time : 2012-02-03 14:29:20
00:30:55 T:3700 INFO: ffmpeg[E74]: handler_name :
00:30:55 T:3700 INFO: ffmpeg[E74]: Stream #0:1(und): Audio: aac (mp4a / 0x6134706D), 44100 Hz, stereo, s16, 63 kb/s
00:30:55 T:3700 INFO: ffmpeg[E74]: Metadata:
00:30:55 T:3700 INFO: ffmpeg[E74]: creation_time : 2012-02-03 14:33:32
00:30:55 T:3700 INFO: ffmpeg[E74]: handler_name : GPAC ISO Audio Handler
00:30:55 T:3700 DEBUG: CDVDInputStreamFile::SetReadRate - set cache throttle rate to 241240 bytes per second
00:30:55 T:3700 NOTICE: Opening video stream: 0 source: 256
00:30:55 T:3700 NOTICE: Creating video codec with codec id: 28
00:30:55 T:3700 DEBUG: CDVDFactoryCodec: compiled in hardware support: CrystalHD:yes DXVA:yes
00:30:55 T:3700 DEBUG: FactoryCodec - Video: - Opening
00:30:55 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/swscale-2.dll)
00:30:56 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/swresample-0.dll)
00:30:56 T:3700 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/players/dvdplayer/avfilter-2.dll)
00:30:56 T:3700 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
00:30:56 T:3700 DEBUG: FactoryCodec - Video: ff-h264 - Opened
00:30:56 T:3700 NOTICE: Creating video thread
00:30:56 T:3700 NOTICE: Opening audio stream: 1 source: 256
00:30:56 T:3700 NOTICE: Finding audio codec for: 86018
00:30:56 T:3700 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
00:30:56 T:1040 NOTICE: Thread CDVDPlayerVideo start, auto delete: false
00:30:56 T:1040 NOTICE: running thread: video_thread
00:30:56 T:1040 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
00:30:56 T:3700 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
00:30:56 T:3700 NOTICE: Creating audio thread
00:30:56 T:1728 NOTICE: Thread CDVDPlayerAudio start, auto delete: false
00:30:56 T:1728 NOTICE: running thread: CDVDPlayerAudio:
00:30:56 T:3700 DEBUG: CDVDPlayer::SetCaching - caching state 1
00:30:56 T:3700 DEBUG: CDVDPlayer::SetCaching - caching state 3
00:30:56 T:1040 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(125125.000000, 1)
00:30:56 T:1040 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
00:30:56 T:3700 DEBUG: CDVDPlayer::CheckContinuity - resync backward :2, prev:125125.000000, curr:41708.333333, diff:-83416.666667
00:30:56 T:1728 NOTICE: Creating audio stream (codec id: 86018, channels: 2, sample rate: 44100, no pass-through)
00:30:56 T:1728 INFO: CSoftAE::MakeStream - AE_FMT_S16NE, 44100, FL,FR
00:30:56 T:1040 INFO: ffmpeg[410]: [h264] Cannot parallelize deblocking type 1, decoding such frames in sequential order
00:30:56 T:1992 NOTICE: 1Channel: Service: Playback started
00:30:56 T:3520 DEBUG: CSoftAE::Run - Sink was forgotten
00:30:56 T:3520 DEBUG: CSoftAE::Run - Sink restart flagged
00:30:56 T:3520 INFO: CSoftAE::LoadSettings - Stereo upmix is enabled
00:30:56 T:3520 INFO: CSoftAE::InternalOpenSink - sink incompatible, re-starting
00:30:56 T:2948 DEBUG: CGUIInfoManager::SetCurrentMovie(http://myname.redirectsite.net/Movies/Av...202009.avi)
00:30:56 T:2948 DEBUG: CVideoDatabase::GetMovieId (http://myname.redirectsite.net/Movies/Av...202009.avi), query = select idMovie from movie where idFile=1
00:30:56 T:2948 DEBUG: CVideoDatabase::GetEpisodeId (http://myname.redirectsite.net/Movies/Av...202009.avi), query = select idEpisode from episode where idFile=1
00:30:56 T:3520 DEBUG: CAESinkDirectSound::Initialize: Using Window handle: 3015648
00:30:56 T:2948 DEBUG: CVideoDatabase::GetMusicVideoId (http://myname.redirectsite.net/Movies/Av...202009.avi), query = select idMVideo from musicvideo where idFile=1
00:30:56 T:3520 DEBUG: CAESinkDirectSound::Initialize: Couldn't create secondary buffer (DSERR_CONTROLUNAVAIL). Trying without LOCHARDWARE.
00:30:56 T:3520 DEBUG: CAESinkDirectSound::Initialize: secondary buffer created
00:30:56 T:3520 DEBUG: CAESinkDirectSound::Initialize: Initializing DirectSound with the following parameters:
00:30:56 T:3520 DEBUG: Audio Device : NVIDIA High Definition Audio
00:30:56 T:3520 DEBUG: Sample Rate : 44100
00:30:56 T:3520 DEBUG: Sample Format : AE_FMT_FLOAT
00:30:56 T:3520 DEBUG: Bits Per Sample : 32
00:30:56 T:3520 DEBUG: Valid Bits/Samp : 32
00:30:56 T:3520 DEBUG: Channel Count : 2
00:30:56 T:3520 DEBUG: Block Align : 8
00:30:56 T:3520 DEBUG: Avg. Bytes Sec : 352800
00:30:56 T:3520 DEBUG: Samples/Block : 32
00:30:56 T:3520 DEBUG: Format cBSize : 22
00:30:56 T:3520 DEBUG: Channel Layout : FL,FR
00:30:56 T:3520 DEBUG: Channel Mask : 3
00:30:56 T:3520 DEBUG: Frames : 441
00:30:56 T:3520 DEBUG: Frame Samples : 882
00:30:56 T:3520 DEBUG: Frame Size : 8
00:30:56 T:3520 DEBUG: CSoftAE::InternalOpenSink - DirectSound Initialized:
00:30:56 T:3520 DEBUG: Output Device : NVIDIA High Definition Audio
00:30:56 T:3520 DEBUG: Sample Rate : 44100
00:30:56 T:3520 DEBUG: Sample Format : AE_FMT_FLOAT
00:30:56 T:3520 DEBUG: Channel Count : 2
00:30:56 T:3520 DEBUG: Channel Layout: FL,FR
00:30:56 T:3520 DEBUG: Frames : 441
00:30:56 T:3520 DEBUG: Frame Samples : 882
00:30:56 T:3520 DEBUG: Frame Size : 8
00:30:56 T:3520 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.0
00:30:56 T:3520 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 3528
00:30:56 T:3520 DEBUG: AERemap: Downmix normalization is disabled
00:30:56 T:3520 DEBUG: CSoftAEStream::CSoftAEStream - Converting from AE_FMT_S16NE to AE_FMT_FLOAT
00:30:56 T:1728 DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
00:30:56 T:3700 DEBUG: CDVDPlayer::HandleMessages - player started 1
00:30:56 T:1040 NOTICE: fps: 23.976024, pwidth: 1280, pheight: 720, dwidth: 1280, dheight: 720
00:30:56 T:1040 DEBUG: CDVDPlayerVideo::OutputPicture - change configuration. 1280x720. framerate: 23.98. format: YV12
00:30:56 T:1040 NOTICE: Display resolution DESKTOP : 1280x720 @ 60.00 - Full Screen (16)
00:30:56 T:1040 DEBUG: CWinRenderer::SelectRenderMethod: Requested render method: 0
00:30:56 T:1040 DEBUG: CWinShader::LoadEffect - loading shader special://xbmc/system/shaders/testshader.fx
00:30:56 T:3520 DEBUG: CAESinkDirectSound::CheckPlayStatus: Resuming Playback
00:30:56 T:3520 WARNING: CWin32DirectSound::GetSpace - buffer underrun - W:10576, P:80, O:3528.
00:30:56 T:1040 DEBUG: CWinRenderer::SelectRenderMethod: Selected render method 1: Pixel Shaders
00:30:56 T:2948 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
00:30:56 T:2948 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
00:30:56 T:2948 DEBUG: Activating window ID: 12005
00:30:56 T:2948 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
00:30:56 T:2948 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
00:30:56 T:2948 INFO: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
00:30:56 T:2948 DEBUG: created video buffer 0
00:30:56 T:2948 DEBUG: created video buffer 1
00:30:56 T:2948 DEBUG: CWinShader::LoadEffect - loading shader special://xbmc/system/shaders/yuv2rgb_d3d.fx
00:30:56 T:2948 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
00:30:56 T:3700 DEBUG: CDVDPlayer::HandleMessages - player started 2
00:30:56 T:3700 DEBUG: CDVDPlayer::SetCaching - caching state 4
00:30:56 T:3520 DEBUG: CSoftAE::Run - Sink restart flagged
00:30:56 T:1728 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(171564.909297, 0)
00:30:56 T:3520 INFO: CSoftAE::LoadSettings - Stereo upmix is enabled
00:30:56 T:3520 DEBUG: CAESinkDirectSound::IsCompatible: Formats compatible - reusing existing sink
00:30:56 T:3520 INFO: CSoftAE::InternalOpenSink - keeping old sink with : AE_FMT_FLOAT, FL,FR, 44100hz
00:30:56 T:3520 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.0
00:30:56 T:3520 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 3528
00:30:56 T:1728 DEBUG: CDVDPlayerAudio:: Discontinuity1 - was:129259.365709, should be:14191.951908, error:-115067.413801
00:30:56 T:3700 DEBUG: CDVDPlayer::SetCaching - caching state 0
00:30:58 T:1728 DEBUG: CDVDPlayerAudio:: Discontinuity2 - was:2043159.566981, should be:2025970.590821, error:-17188.976160
00:30:59 T:2948 DEBUG: ------ Window Init (VideoOSD.xml) ------
00:30:59 T:2948 INFO: Loading skin file: VideoOSD.xml, load type: KEEP_IN_MEMORY
00:31:00 T:2948 DEBUG: ------ Window Init (Pointer.xml) ------
00:31:00 T:1728 DEBUG: CDVDPlayerAudio:: Discontinuity2 - was:4040582.347903, should be:4026217.129008, error:-14365.218895
00:31:01 T:2948 DEBUG: CApplication:
00:31:01 T:2948 DEBUG: CApplication::ExecuteXBMCAction : Translating PlayerControl(Stop)
00:31:01 T:2948 DEBUG: CApplication::ExecuteXBMCAction : To PlayerControl(Stop)
00:31:01 T:2948 NOTICE: CDVDPlayer::CloseFile()
00:31:01 T:2948 NOTICE: DVDPlayer: waiting for threads to exit
00:31:01 T:3700 NOTICE: CDVDPlayer::OnExit()
00:31:01 T:3700 NOTICE: DVDPlayer: closing audio stream
00:31:01 T:3700 NOTICE: Closing audio stream
00:31:01 T:3700 NOTICE: Waiting for audio thread to exit
00:31:01 T:1728 NOTICE: thread end: CDVDPlayerAudio::OnExit()
00:31:01 T:1728 DEBUG: Thread CDVDPlayerAudio 1728 terminating
00:31:01 T:3700 NOTICE: Closing audio device
00:31:01 T:3700 DEBUG: CSoftAEStream::~CSoftAEStream - Destructed
00:31:01 T:3700 NOTICE: Deleting audio codec
00:31:01 T:3700 NOTICE: DVDPlayer: closing video stream
00:31:01 T:3700 NOTICE: Closing video stream
00:31:01 T:3700 NOTICE: waiting for video thread to exit
00:31:01 T:3520 DEBUG: CSoftAE::Run - Sink restart flagged
00:31:01 T:3520 INFO: CSoftAE::LoadSettings - Stereo upmix is enabled
00:31:01 T:3520 DEBUG: CAESinkDirectSound::IsCompatible: Formats compatible - reusing existing sink
00:31:01 T:3520 INFO: CSoftAE::InternalOpenSink - keeping old sink with : AE_FMT_FLOAT, FL,FR, 44100hz
00:31:01 T:3520 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.0
00:31:01 T:3520 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 3528
00:31:01 T:1040 NOTICE: thread end: video_thread
00:31:01 T:1040 DEBUG: Thread CDVDPlayerVideo 1040 terminating
00:31:01 T:3700 NOTICE: deleting video codec
00:31:01 T:3700 NOTICE: CDVDPlayer::OnExit() deleting demuxer
00:31:01 T:3700 NOTICE: CDVDPlayer::OnExit() deleting input stream
00:31:01 T:3820 DEBUG: Thread CFileCache 3820 terminating
00:31:01 T:3700 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
00:31:01 T:3700 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
00:31:01 T:3700 DEBUG: Thread CDVDPlayer 3700 terminating
00:31:01 T:2948 NOTICE: DVDPlayer: finished waiting
00:31:01 T:2948 DEBUG: CGUIWindowManager:
00:31:01 T:2948 DEBUG: ------ Window Deinit (VideoOSD.xml) ------
00:31:01 T:2948 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
00:31:01 T:2948 DEBUG: CGUIWindowManager:
00:31:01 T:2948 DEBUG: ------ Window Init (MyVideoNav.xml) ------
