Unable to play some videos, how to get more log-info - balta - 2010-05-15
Hi,
I'm using current svn-version of xbmc pvr-testing2 with Linux.
I have problems playing some mkv-files, it does not start to play, but in the log I cannot find any helpful:
Code: 13:18:08 T:139867868252224 M:5187256320 DEBUG: SDLKeyboard: scancode: 108, sym: 271, unicode: 13, modifier: 0
13:18:08 T:139867868252224 M:5187256320 DEBUG: OnKey: 61548 pressed, action is Select
13:18:08 T:139867868252224 M:5187256320 DEBUG: CDatabase: Connecting to database MyVideos34.db at /home/arthas/.xbmc/userdata/Database:
13:18:08 T:139867868252224 M:5187256320 DEBUG: new file set audiostream:0
13:18:08 T:139867868252224 M:5187256320 DEBUG: CDatabase: Connecting to database MyVideos34.db at /home/arthas/.xbmc/userdata/Database:
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers(/media/VideoBird/BluRay/Avatar/Avatar.mkv)
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
13:18:08 T:139867868252224 M:5187256320 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
13:18:08 T:139867868252224 M:5185732608 NOTICE: DVDPlayer: Opening: /media/VideoBird/BluRay/Avatar/Avatar.mkv
13:18:08 T:139867868252224 M:5185732608 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
13:18:08 T:139867418442000 M:5185732608 DEBUG: thread start, auto delete: 0
13:18:08 T:139867418442000 M:5185732608 NOTICE: Creating InputStream
13:18:08 T:139867418442000 M:5185732608 INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: START
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: Checking for common subdirs...
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: Done (time: 1 ms)
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: Searching for subtitles...
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: Done (time: 1 ms)
13:18:08 T:139867418442000 M:5185732608 DEBUG: CacheSubtitles: END (total time: 3 ms)
13:18:08 T:139867418442000 M:5185732608 INFO: CDVDFactorySubtitle::GetSubtitles, searching subtitles done
13:18:08 T:139867418442000 M:5185732608 NOTICE: Creating Demuxer
13:18:08 T:139867418442000 M:5185732608 DEBUG: SECTION:LoadDLL(special://xbmc/system/players/dvdplayer/avformat-52-x86_64-linux.so)
13:18:08 T:139867418442000 M:5185732608 DEBUG: Loading: /usr/local/share/xbmc/system/players/dvdplayer/avformat-52-x86_64-linux.so
13:18:08 T:139867418442000 M:5185732608 DEBUG: Open - probing detected format [matroska]
13:18:08 T:139867418442000 M:5185732608 ERROR: Open - Error, could not open file /media/VideoBird/BluRay/Avatar/Avatar.mkv
13:18:08 T:139867418442000 M:5185732608 ERROR: OpenDemuxStream - Error creating demuxer
13:18:08 T:139867418442000 M:5185732608 NOTICE: CDVDPlayer::OnExit()
13:18:08 T:139867418442000 M:5185732608 NOTICE: CDVDPlayer::OnExit() deleting input stream
13:18:08 T:139867418442000 M:5185732608 DEBUG: Thread 139867418442000 terminating
13:18:08 T:139867868252224 M:5185732608 DEBUG: CAnnouncementManager - Announcement: PlaybackStopped from xbmc
13:18:08 T:139867868252224 M:5185732608 DEBUG: OnPlayBackStopped - Playback was stopped
13:18:08 T:139867868252224 M:5185732608 ERROR: Playlist Player: skipping unplayable item: 0, path [/media/VideoBird/BluRay/Avatar/Avatar.mkv]
13:18:08 T:139867868252224 M:5185732608 DEBUG: Playlist Player: one or more items failed to play... aborting playback
13:18:08 T:139867868252224 M:5185732608 INFO: Loading skin file: DialogOK.xml
13:18:08 T:139867868252224 M:5185732608 DEBUG: Load DialogOK.xml: 3.33ms
13:18:08 T:139867868252224 M:5185732608 DEBUG: ------ Window Init (DialogOK.xml) ------
13:18:08 T:139867868252224 M:5185732608 DEBUG: Alloc resources: 0.05ms (0.00 ms skin load)
13:18:08 T:139867868252224 M:5185732608 NOTICE: CDVDPlayer::CloseFile()
13:18:08 T:139867868252224 M:5185732608 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
13:18:08 T:139867868252224 M:5185732608 NOTICE: DVDPlayer: waiting for threads to exit
13:18:08 T:139867868252224 M:5185732608 NOTICE: DVDPlayer: finished waiting
13:18:08 T:139867868252224 M:5185732608 DEBUG: LinuxRendererGL: Cleaning up GL resources
13:18:09 T:139867868252224 M:5187518464 DEBUG: SDLKeyboard: scancode: 108, sym: 271, unicode: 13, modifier: 0
13:18:09 T:139867868252224 M:5187518464 DEBUG: OnKey: 61548 pressed, action is Select
13:18:10 T:139867868252224 M:5187764224 DEBUG: ------ Window Deinit (DialogOK.xml) ------
13:18:10 T:139867472255248 M:5187764224 DEBUG: thread start, auto delete: 0
13:18:10 T:139867472255248 M:5187764224 DEBUG: CDatabase: Connecting to database MyVideos34.db at /home/arthas/.xbmc/userdata/Database:
13:18:10 T:139867589286160 M:5187764224 DEBUG: DoWork - trying to extract thumb from video file /media/VideoBird/BluRay/Avatar/Avatar.mkv
13:18:10 T:139867472255248 M:5187764224 DEBUG: CDatabase: Connecting to database MyVideos34.db at /home/arthas/.xbmc/userdata/Database:
13:18:10 T:139867472255248 M:5187764224 DEBUG: Thread 139867472255248 terminating
13:18:10 T:139867589286160 M:5187764224 DEBUG: Open - probing detected format [matroska]
13:18:10 T:139867589286160 M:5187764224 ERROR: Open - Error, could not open file /media/VideoBird/BluRay/Avatar/Avatar.mkv
13:18:10 T:139867589286160 M:5187764224 ERROR: ExtractThumb - Error creating demuxer
I can't find any pattern which videos can be played and which not. Is there any way to get more log-info about this?
Is this a known problem in current svn-version?
Greets
- kraqh3d - 2010-05-15
That looks like a permissions problem as you're getting several errors that the file cannot be opened.
- balta - 2010-05-15
kraqh3d Wrote:That looks like a permissions problem as you're getting several errors that the file cannot be opened.
This can't be a permission-problem. Other files in the same directory with the same permissions (644) and other players as MPlayer or VLC can play it without problems.
- kraqh3d - 2010-05-15
Error, could not open file /media/VideoBird/BluRay/Avatar/Avatar.mkv
I don't know what to tell you. There's really no other reason why Xbmc would not be able to open the file.
Put another media file in /media/VideoBird/BluRay/Avatar/ as a test, and move Avatar.mkv to another folder as a test.
- balta - 2010-05-16
Hi,
the permissions are alright, I tested it with changing to 777 and so on
To debug this I changed the code in xbmc to the following:
Code: // open the demuxer
int openresult = m_dllAvFormat.av_open_input_stream(&m_pFormatContext, m_ioContext, strFile.c_str(), iformat, NULL);
if (openresult < 0)
{
CLog::Log(LOGDEBUG, "%i:%i:%i:%i:%i:%i:%i:%i:%i", AVERROR_INVALIDDATA, AVERROR_IO, AVERROR_NOENT, AVERROR_NOMEM, AVERROR_NUMEXPECTED, AVERROR_UNKNOWN, AVERROR_EOF, AVERROR_NOFMT, AVERROR_NOTSUPP);
CLog::Log(LOGERROR, "%s - Error, could not open file %s (%i)", __FUNCTION__, strFile.c_str(), openresult);
Dispose();
return false;
}
Now I get the following:
Code: 02:26:05 T:139752654129424 M:4540411904 DEBUG: -22:-5:-2:-12:-33:-22:-32:-84:-38
02:26:05 T:139752654129424 M:4540411904 ERROR: Open - Error, could not open file /media/VideoBird/BluRay/Avatar/Avatar.mkv (-12)
So the error is AVERROR_NOMEM, according to ffmpeg/libavutil/error.h this means not enough memory... How can this be? I have 6GB RAM Does anybody know which memory is meant here?
Edit:
I remember, I had a similiar problem a few weeks ago with vlc: http://trac.videolan.org/vlc/ticket/3570. The problem there was, that I forgot to compile in the mkv-module in vlc, and so libavformat had to be used as fallback. And libavformat wasn't able to play the file. The interessesting part is, that vlc with mkv-module plays it without problems, also working players are mplayer and xine. ffplay breaks with the same message as xbmc: Cannot allocate memory. I uploaded the first 20MB of the file, which shows the same behaviour as the full file, if you want to test: http://rapidshare.com/files/380017569/title00.part.mkv.html
So this seems to be a bug in libavformat? Should I open a bug-report?
- kraqh3d - 2010-05-16
Wow. Nice find. Definitely open a trac ticket.
- balta - 2010-05-17
I reported it in trac: http://trac.xbmc.org/ticket/9229
Also I noticed that the files play fine it I create them without subtitles.
|