Wed Jul 18, 2012 8:59 pm
File causes library building process to fail
So, I noticed while updating a huge folder full of video files that one of them caused the library building process to freeze. I renamed that file "b.mkv", put that file in its own separate folder, and added some files that are known to work to that folder as well ("a.mkv" and "c.mkv"). I then pointed the program to that folder and confirmed that it was that one file, independent of file path and filename, that caused the process to fail. I left the process alone for several hours to confirm that it wasn't just taking an extraordinarily long time. I also updated ffmpeg. This file is confirmed to work in VLC, MPC, and ffplay.
Anyway, here's the details on the file:
Some ffmpeg info
The mediainfo info:
Finally the debug log from that process:
Now, even though the log says "library updated" the console still has the green dot and displays "1 (a.mkv)". I have other files that do this as well, all mkv, probably encoded the same way.
Anyway, here's the details on the file:
Some ffmpeg info
- Code:
C:\Program Files\Serviio\lib>ffmpeg.exe -i "D:\mkv\b.mkv"
ffmpeg version N-42547-g7543fd8 Copyright (c) 2000-2012 the FFmpeg developers
built on Jul 15 2012 21:40:06 with gcc 4.7.1
configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-ru
ntime-cpudetect --enable-avisynth --enable-bzlib --enable-frei0r --enable-libass
--enable-libcelt --enable-libopencore-amrnb --enable-libopencore-amrwb --enable
-libfreetype --enable-libgsm --enable-libmp3lame --enable-libnut --enable-libope
njpeg --enable-librtmp --enable-libschroedinger --enable-libspeex --enable-libth
eora --enable-libutvideo --enable-libvo-aacenc --enable-libvo-amrwbenc --enable-
libvorbis --enable-libvpx --enable-libx264 --enable-libxavs --enable-libxvid --e
nable-zlib
libavutil 51. 65.100 / 51. 65.100
libavcodec 54. 40.100 / 54. 40.100
libavformat 54. 16.104 / 54. 16.104
libavdevice 54. 1.100 / 54. 1.100
libavfilter 3. 2.100 / 3. 2.100
libswscale 2. 1.100 / 2. 1.100
libswresample 0. 15.100 / 0. 15.100
libpostproc 52. 0.100 / 52. 0.100
Input #0, matroska,webm, from 'D:\mkv\b.mkv':
Metadata:
creation_time : 2012-04-04 04:46:46
Duration: 00:11:11.59, start: 0.000000, bitrate: 2199 kb/s
Stream #0:0: Video: h264 (High), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 29.97
fps, 29.97 tbr, 1k tbn, 59.94 tbc (default)
Stream #0:1: Audio: aac, 48000 Hz, 5.1, s16 (default)
At least one output file must be specified
The mediainfo info:
- Code:
General
Unique ID : 235839725617131727413953996012024882388 (0xB16D1436FF9CFEBCBA1A9D539595E4D4)
Complete name : D:\mkv\b.mkv
Format : Matroska
Format version : Version 2
File size : 176 MiB
Duration : 11mn 11s
Overall bit rate : 2 200 Kbps
Encoded date : UTC 2012-04-04 04:46:46
Writing application : mkvmerge v4.8.0 ('I Got The...') built on May 24 2011 03:12:58
Writing library : libebml v1.2.0 + libmatroska v1.1.0
Video
ID : 1
Format : AVC
Format/Info : Advanced Video Codec
Format profile : High@L5.1
Format settings, CABAC : Yes
Format settings, ReFrames : 2 frames
Muxing mode : Header stripping
Codec ID : V_MPEG4/ISO/AVC
Duration : 11mn 11s
Width : 1 280 pixels
Height : 720 pixels
Display aspect ratio : 16:9
Frame rate : 29.970 fps
Color space : YUV
Chroma subsampling : 4:2:0
Bit depth : 8 bits
Scan type : Progressive
Writing library : x264 core 120 r2120 0c7dab9
Encoding settings : cabac=1 / ref=2 / deblock=1:1:1 / analyse=0x3:0x113 / me=hex / subme=6 / psy=1 / psy_rd=1.00:0.00 / mixed_ref=1 / me_range=16 / chroma_me=1 / trellis=1 / 8x8dct=1 / cqm=0 / deadzone=21,11 / fast_pskip=1 / chroma_qp_offset=-2 / threads=6 / sliced_threads=0 / nr=0 / decimate=1 / interlaced=0 / bluray_compat=0 / constrained_intra=0 / bframes=1 / b_pyramid=0 / b_adapt=1 / b_bias=0 / direct=1 / weightb=1 / open_gop=0 / weightp=2 / keyint=250 / keyint_min=25 / scenecut=40 / intra_refresh=0 / rc_lookahead=30 / rc=crf / mbtree=1 / crf=20.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / ip_ratio=1.40 / aq=1:0.60
Default : Yes
Forced : No
Audio
ID : 2
Format : AAC
Format/Info : Advanced Audio Codec
Format profile : LC
Codec ID : A_AAC
Duration : 11mn 11s
Channel(s) : 6 channels
Channel positions : Front: L C R, Side: L R, LFE
Sampling rate : 48.0 KHz
Compression mode : Lossy
Default : Yes
Forced : No
Finally the debug log from that process:
- Code:
2012-07-18 13:48:01,112 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-07-18 13:48:01,113 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = search_hidden_files)
2012-07-18 13:48:01,114 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = search_hidden_files, value = false)
2012-07-18 13:48:01,115 DEBUG [FeedUpdaterThread] Checking for new and expired online resources
2012-07-18 13:48:01,115 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-07-18 13:48:01,115 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = search_updated_files)
2012-07-18 13:48:01,115 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = search_updated_files, value = true)
2012-07-18 13:48:01,116 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = repository_automatic_check)
2012-07-18 13:48:01,117 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = repository_automatic_check, value = true)
2012-07-18 13:48:01,117 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = repository_automatic_check_interval)
2012-07-18 13:48:01,118 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = repository_automatic_check_interval, value = 5)
2012-07-18 13:48:01,119 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = online_feed_max_num_items)
2012-07-18 13:48:01,119 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = online_feed_max_num_items, value = 20)
2012-07-18 13:48:01,120 DEBUG [ConfigEntryDAOImpl] Reading a ConfigEntry (name = online_feed_expiry_interval)
2012-07-18 13:48:01,120 DEBUG [ConfigEntryDAOImpl] Updating ConfigEntry (name = online_feed_expiry_interval, value = 24)
2012-07-18 13:48:01,124 INFO [LibraryAdditionsCheckerThread] Finished looking for newly added files
2012-07-18 13:48:01,221 INFO [LibraryUpdatesCheckerThread] Finished looking for updates to currently shared files
2012-07-18 13:48:01,322 DEBUG [RepositoryServerResource] Updating repository with values: Repository [id=null, folder=D:\mkv, keepScanningForUpdates=true, lastScanned=null, supportedFileTypes=[VIDEO], supportsOnlineMetadata=false]
2012-07-18 13:48:01,322 DEBUG [RepositoryDAOImpl] Reading all Repositories
2012-07-18 13:48:01,323 DEBUG [RepositoryService] Found 0 repositories to be removed
2012-07-18 13:48:01,323 DEBUG [RepositoryDAOImpl] Creating a new Repository (folder = D:\mkv)
2012-07-18 13:48:01,324 INFO [LibraryAdditionsCheckerThread] Started looking for newly added files
2012-07-18 13:48:01,324 DEBUG [RepositoryDAOImpl] Reading all Repositories
2012-07-18 13:48:01,326 DEBUG [LibraryAdditionsCheckerThread] Looking for files to share in folder: D:\mkv
2012-07-18 13:48:01,326 INFO [LibraryUpdatesCheckerThread] Started looking for updates to currently shared files
2012-07-18 13:48:01,326 DEBUG [RepositoryDAOImpl] Reading all Repositories
2012-07-18 13:48:01,327 DEBUG [LibraryUpdatesCheckerThread] Looking for removed/updated files in repository: D:\mkv
2012-07-18 13:48:01,327 DEBUG [MediaItemDAOImpl] Reading MediaItems for Repository (id = 24)
2012-07-18 13:48:01,327 DEBUG [MediaItemDAOImpl] Reading dirty MediaItems for Repository (id = 24)
2012-07-18 13:48:01,328 DEBUG [RepositoryDAOImpl] Marking Repository 24 as scanned with current timestamp
2012-07-18 13:48:01,346 DEBUG [LibraryAdditionsCheckerThread] Found file 'a.mkv', checking if it's already in the Library
2012-07-18 13:48:01,346 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item a.mkv
2012-07-18 13:48:01,346 DEBUG [MediaItemDAOImpl] Media item a.mkv doesn't exist in DB yet
2012-07-18 13:48:01,347 DEBUG [LibraryAdditionsCheckerThread] File not in Library, will add it
2012-07-18 13:48:01,347 DEBUG [VideoExtractionStrategy] Extracting metadata of video file: D:\mkv\a.mkv
2012-07-18 13:48:01,347 DEBUG [FFMPEGWrapper] Invoking FFMPEG to retrieve media information for file: D:\mkv\a.mkv
2012-07-18 13:48:01,347 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\mkv\a.mkv
2012-07-18 13:48:01,382 DEBUG [FFmpegMetadataRetriever] Retrieving H264 profile/level for file 'D:\mkv\a.mkv'
2012-07-18 13:48:01,382 DEBUG [FFMPEGWrapper] Invoking FFMPEG to retrieve H264 header for file: D:\mkv\a.mkv
2012-07-18 13:48:01,382 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\mkv\a.mkv -vframes 1 -vcodec copy -f h264 -vbsf h264_mp4toannexb -an pipe:
2012-07-18 13:48:01,398 DEBUG [RepositoryDAOImpl] Reading all Repositories
2012-07-18 13:48:01,399 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-07-18 13:48:01,421 DEBUG [FFmpegMetadataRetriever] H264 Level value stored in the AVC header (4.1) is different than one based on ref_frames value (4), the higher will be stored
2012-07-18 13:48:01,421 DEBUG [FFmpegMetadataRetriever] File 'D:\mkv\a.mkv' has H264 profile HIGH, level 4.1 and 8 ref frames
2012-07-18 13:48:01,421 DEBUG [FFMPEGWrapper] Invoking FFMPEG to retrieve thumbnail for file: D:\mkv\a.mkv
2012-07-18 13:48:01,421 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -ss 120 -i D:\mkv\a.mkv -an -vframes 1 -f image2 pipe:
2012-07-18 13:48:01,505 DEBUG [RepositoryDAOImpl] Reading all Repositories
2012-07-18 13:48:01,506 DEBUG [OnlineRepositoryDAOImpl] Reading all OnlineRepositories
2012-07-18 13:48:01,590 DEBUG [LibraryManager] Metadata found via extractor EMBEDDED: VideoMetadata [title=a, filePath=D:\mkv\a.mkv, fileSize=664511805, audioBitrate=384, audioCodec=AC3, audioStreamIndex=1, bitrate=4135, channels=6, container=MATROSKA, contentType=UNKNOWN, coverImage=org.serviio.library.local.metadata.ImageDescriptor@71e39149, duration=1285, episodeNumber=null, fps=23.976, frequency=48000, h264Level=4.1, h264Profile=HIGH, ftyp=null, height=720, seasonNumber=null, seriesName=null, timestampType=null, videoBitrate=null, videoCodec=H264, videoStreamIndex=0, width=1280]
2012-07-18 13:48:01,590 DEBUG [VideoService] Adding video into database: a
2012-07-18 13:48:01,594 DEBUG [GenreDAOImpl] Reading a Genre (name = Unknown)
2012-07-18 13:48:01,594 DEBUG [GenreService] Genre Unknown not found, creating a new one
2012-07-18 13:48:01,594 DEBUG [GenreDAOImpl] Creating a new Genre (name = Unknown)
2012-07-18 13:48:01,596 DEBUG [CoverImageService] Resizing and storing cover art image
2012-07-18 13:48:01,596 DEBUG [ImageUtils] Starting image resize, size = 62647 bytes
2012-07-18 13:48:01,635 DEBUG [ImageUtils] Returning resized image, size = 4759 bytes
2012-07-18 13:48:01,635 DEBUG [CoverImageService] Image successfully resized
2012-07-18 13:48:01,635 DEBUG [CoverImageDAOImpl] Creating a new ImageCover (length = 4759)
2012-07-18 13:48:01,637 DEBUG [VideoDAOImpl] Creating a new Video (title = a)
2012-07-18 13:48:01,640 DEBUG [PersonDAOImpl] Adding a Person Unknown to media item 847 as DIRECTOR
2012-07-18 13:48:01,640 DEBUG [PersonDAOImpl] Reading a Person (name = Unknown)
2012-07-18 13:48:01,641 DEBUG [PersonDAOImpl] Creating a new Person (name = Unknown)
2012-07-18 13:48:01,642 DEBUG [PersonDAOImpl] Checking if person 255 has a role DIRECTOR for media item 847
2012-07-18 13:48:01,646 DEBUG [PersonDAOImpl] Adding a Person Unknown to media item 847 as PRODUCER
2012-07-18 13:48:01,646 DEBUG [PersonDAOImpl] Reading a Person (name = Unknown)
2012-07-18 13:48:01,646 DEBUG [PersonDAOImpl] Checking if person 255 has a role PRODUCER for media item 847
2012-07-18 13:48:01,649 DEBUG [PersonDAOImpl] Adding a Person Unknown to media item 847 as ACTOR
2012-07-18 13:48:01,649 DEBUG [PersonDAOImpl] Reading a Person (name = Unknown)
2012-07-18 13:48:01,650 DEBUG [PersonDAOImpl] Checking if person 255 has a role ACTOR for media item 847
2012-07-18 13:48:01,653 DEBUG [MetadataDescriptorDAOImpl] Creating a new MetadataDescriptor (type = EMBEDDED, mediaItemId = 847)
2012-07-18 13:48:01,655 INFO [LibraryAdditionsCheckerThread] Added file 'a.mkv' (title: a) to Library
2012-07-18 13:48:01,675 DEBUG [LibraryAdditionsCheckerThread] Found file 'b.mkv', checking if it's already in the Library
2012-07-18 13:48:01,675 DEBUG [MediaItemDAOImpl] Checking if DB already contains media item b.mkv
2012-07-18 13:48:01,675 DEBUG [MediaItemDAOImpl] Media item b.mkv doesn't exist in DB yet
2012-07-18 13:48:01,675 DEBUG [LibraryAdditionsCheckerThread] File not in Library, will add it
2012-07-18 13:48:01,676 DEBUG [VideoExtractionStrategy] Extracting metadata of video file: D:\mkv\b.mkv
2012-07-18 13:48:01,676 DEBUG [FFMPEGWrapper] Invoking FFMPEG to retrieve media information for file: D:\mkv\b.mkv
2012-07-18 13:48:01,676 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\mkv\b.mkv
2012-07-18 13:48:01,716 DEBUG [FFmpegMetadataRetriever] Retrieving H264 profile/level for file 'D:\mkv\b.mkv'
2012-07-18 13:48:01,716 DEBUG [FFMPEGWrapper] Invoking FFMPEG to retrieve H264 header for file: D:\mkv\b.mkv
2012-07-18 13:48:01,716 DEBUG [ProcessExecutor] Starting C:\Program Files\Serviio\bin\\..\lib/ffmpeg.exe -i D:\mkv\b.mkv -vframes 1 -vcodec copy -f h264 -vbsf h264_mp4toannexb -an pipe:
2012-07-18 13:48:03,412 DEBUG [AbstractCDSLibraryIndexingListener] Library updated, notifying CDS
2012-07-18 13:48:03,412 DEBUG [LocalContentCacheDecorator] Cleared cache (local_resetafterplay)
2012-07-18 13:48:03,412 DEBUG [LocalContentCacheDecorator] Cleared cache (local_default)
Now, even though the log says "library updated" the console still has the green dot and displays "1 (a.mkv)". I have other files that do this as well, all mkv, probably encoded the same way.
