2015-05-25, 19:50
Today I noticed a brand new problem on my Kodibuntu system. One song will end abruptly, after only playing for a few seconds, then skip to the next song in the playlist or sometimes restart the current song. In the debug log, I see lines about "unrecognized ID3 frame detected". Opening the file in ffmpeg, I see similar errors, so apparently something is wrong with the file... But I have played this file many times on this same system, so what could have happened to it? Below is a partial debug log from Kodi, then an ffmpeg sample.
Code:
10:41:22 T:139770223118080 DEBUG: OnPlayBackStopped: play state was 2, starting 1
10:41:22 T:139770223118080 DEBUG: Thread PAPlayer 139770223118080 terminating
10:41:22 T:139771962869696 DEBUG: Open - probing detected format [mp3]
10:41:22 T:139771962869696 DEBUG: Open - setting usetoc to 0 for accurate VBR MP3 seek
10:41:22 T:139771962869696 DEBUG: Open - avformat_find_stream_info starting
10:41:22 T:139771962869696 DEBUG: Open - av_find_stream_info finished
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Input #0, mp3, from 'musicdb://songs/5358.mp3?albumid=584':
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Metadata:
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: title : These Are My People
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: artist : Rodney Atkins
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: album : If You're Going Through Hell
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: genre : Country
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: publisher : Curb Records
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: composer : Dave Berg/Rivers Rutherford
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: track : 1/10
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: TBPM : 90
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Rip date : 2006-07-13
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: album_artist : Rodney Atkins
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Source : CD (LP)
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: encoder : LAME
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Ripping tool : EAC
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Release type : Normal Release
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: date : 2006-07-18
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Duration: 00:03:33.71, start: 0.025057, bitrate: 242 kb/s
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Stream #0:0: Audio: mp3, 44100 Hz, stereo, s16p, 240 kb/s
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: Metadata:
10:41:22 T:139771962869696 INFO: ffmpeg[7F1F323247C0]: encoder : LAME3.90.
10:41:22 T:139771962869696 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
10:41:22 T:139771962869696 DEBUG: FactoryCodec - Audio: passthrough - Opening
10:41:22 T:139771962869696 DEBUG: FactoryCodec - Audio: passthrough - Failed
10:41:22 T:139771962869696 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
10:41:22 T:139771962869696 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: GEOB
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: RVAD
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TBPM
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TCOM
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TDAT
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TPUB
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TSSE
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Rip date
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Source
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Ripping tool
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Release type
10:41:22 T:139771962869696 DEBUG: ffmpeg[7F1F323247C0]: [mp3] Could not update timestamps for skipped samples.
10:41:22 T:139771962869696 DEBUG: SeekTime - seek ended up on time 0
10:41:22 T:139771962869696 DEBUG: Previous line repeats 1 times.
10:41:22 T:139771962869696 INFO: AudioDecoder: File is queued
10:41:22 T:139771962869696 DEBUG: AudioDecoder::GetReplayGain - Final Replaygain applied: 1.000000, Track/Album Gain 89.000000, Peak 0.000000
10:41:22 T:139771962869696 INFO: PAPlayer::PrepareStream - Ready
10:41:22 T:139771962869696 DEBUG: PlayFile: OpenFile succeed, play state 1
10:41:22 T:139770223118080 NOTICE: Thread PAPlayer start, auto delete: false
10:41:22 T:139770223118080 DEBUG: PAPlayer::Process - Playback started
10:41:22 T:139770223118080 DEBUG: OnPlayBackStarted: play state was 1, starting 0
10:41:22 T:139771461994240 DEBUG: OnInitialize() started
10:41:22 T:139771461994240 DEBUG: Updating visualisation albumart: /media/Tera/Music/Rodney Atkins/If You're Going Through Hell/cover.jpg
10:41:22 T:139771461994240 DEBUG: OnInitialize() done
10:41:22 T:139771962869696 DEBUG: CGUIInfoManager::SetCurrentSong(musicdb://songs/5358.mp3?albumid=584)
10:41:22 T:139771962869696 DEBUG: Loading additional tag info for file /media/Tera/Music/Rodney Atkins/If You're Going Through Hell/01 These Are My People.mp3
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: GEOB
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: RVAD
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TBPM
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TCOM
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TDAT
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TPUB
10:41:22 T:139771962869696 DEBUG: unrecognized ID3 frame detected: TSSE
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Rip date
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Source
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Ripping tool
10:41:22 T:139771962869696 DEBUG: unrecognized user text tag detected: TXXX:Release type
10:41:22 T:139771962869696 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
10:41:22 T:139771962869696 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
10:41:22 T:139771962869696 DEBUG: Updating visualisation albumart: /media/Tera/Music/Rodney Atkins/If You're Going Through Hell/cover.jpg
10:41:22 T:139771962869696 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
10:41:22 T:139771144722176 DEBUG: webserver: request received for /jsonrpc
10:41:23 T:139770239903488 DEBUG: Previous line repeats 3 times.
10:41:23 T:139770239903488 DEBUG: webserver: request received for /jsonrpc?tm=1432575687265
10:41:23 T:139770239903488 DEBUG: webserver: request received for /jsonrpc?tm=1432575687269
10:41:23 T:139771144722176 DEBUG: webserver: request received for /jsonrpc
10:41:29 T:139770239903488 DEBUG: Previous line repeats 21 times.
10:41:29 T:139770239903488 DEBUG: webserver: request received for /jsonrpc?tm=1432575693265
10:41:29 T:139770239903488 DEBUG: webserver: request received for /jsonrpc?tm=1432575693284
10:41:29 T:139771144722176 DEBUG: webserver: request received for /jsonrpc
10:41:30 T:139770223118080 DEBUG: Previous line repeats 3 times.
10:41:30 T:139770223118080 INFO: ffmpeg[7F1ECA7FC700]: [mp3] overread, skip -8 enddists: -5 -5
10:41:30 T:139770223118080 INFO: ffmpeg[7F1ECA7FC700]: [mp3] overread, skip -5 enddists: -4 -4
10:41:30 T:139770223118080 INFO: ffmpeg[7F1ECA7FC700]: [mp3] overread, skip -5 enddists: -2 -2
10:41:30 T:139770223118080 ERROR: ffmpeg[7F1ECA7FC700]: [mp3] Header missing
10:41:30 T:139770223118080 ERROR: Previous line repeats 1 times.
10:41:30 T:139770223118080 ERROR: CAudioDecoder: Error while decoding 1
10:41:30 T:139770223118080 INFO: PAPlayer::ProcessStream - Stream Finished
10:41:30 T:139770223118080 DEBUG: OnQueueNextItem: play state was 2, starting 0
10:41:30 T:139770346690304 NOTICE: Thread JobWorker start, auto delete: true
10:41:30 T:139770346690304 DEBUG: Open - probing detected format [mp3]
10:41:30 T:139770346690304 DEBUG: Open - setting usetoc to 0 for accurate VBR MP3 seek
10:41:30 T:139770346690304 DEBUG: Open - avformat_find_stream_info starting
10:41:30 T:139770346690304 DEBUG: Open - av_find_stream_info finished
10:41:30 T:139770346690304 INFO: ffmpeg[7F1ED1DD5700]: Input #0, mp3, from 'musicdb://songs/5359.mp3?albumid=584':
10:41:30 T:139770346690304 INFO: ffmpeg[7F1ED1DD5700]: Metadata:
10:41:30 T:139770346690304 INFO: ffmpeg[7F1ED1DD5700]: title : About The South
10:41:30 T:139770346690304 INFO: ffmpeg[7F1ED1DD5700]: artist : Rodney AtkinsCode:
$ ffmpeg -i 01\ These\ Are\ My\ People.mp3 test.mp3
ffmpeg version 2.5.git Copyright (c) 2000-2015 the FFmpeg developers
built on Feb 8 2015 16:44:44 with Apple LLVM version 6.0 (clang-600.0.56) (based on LLVM 3.5svn)
configuration: --prefix=/opt/local --enable-swscale --enable-avfilter --enable-avresample --enable-libmp3lame --enable-libvorbis --enable-libopus --enable-libtheora --enable-libschroedinger --enable-libopenjpeg --enable-libmodplug --enable-libvpx --enable-libspeex --enable-libass --enable-libbluray --enable-lzma --enable-gnutls --enable-fontconfig --enable-libfreetype --enable-libfribidi --disable-indev=jack --disable-outdev=xv --mandir=/opt/local/share/man --enable-shared --enable-pthreads --cc=/usr/bin/clang --enable-vda --arch=x86_64 --enable-yasm --enable-gpl --enable-postproc --enable-libx264 --enable-libxvid --enable-nonfree --enable-libfdk-aac --enable-libfaac
libavutil 54. 17.100 / 54. 17.100
libavcodec 56. 20.100 / 56. 20.100
libavformat 56. 19.100 / 56. 19.100
libavdevice 56. 4.100 / 56. 4.100
libavfilter 5. 8.100 / 5. 8.100
libavresample 2. 1. 0 / 2. 1. 0
libswscale 3. 1.101 / 3. 1.101
libswresample 1. 1.100 / 1. 1.100
libpostproc 53. 3.100 / 53. 3.100
Input #0, mp3, from '01 These Are My People.mp3':
Metadata:
title : These Are My People
artist : Rodney Atkins
album : If You're Going Through Hell
genre : Country
publisher : Curb Records
composer : Dave Berg/Rivers Rutherford
TBPM : 90
Rip date : 2006-07-13
track : 1/10
Source : CD (LP)
encoder : LAME
Ripping tool : EAC
Release type : Normal Release
album_artist : Rodney Atkins
date : 2006-07-18
Duration: 00:03:33.71, start: 0.025057, bitrate: 242 kb/s
Stream #0:0: Audio: mp3, 44100 Hz, stereo, s16p, 240 kb/s
Metadata:
encoder : LAME3.90.
Output #0, mp3, to 'test.mp3':
Metadata:
TIT2 : These Are My People
TPE1 : Rodney Atkins
TALB : If You're Going Through Hell
TCON : Country
TPUB : Curb Records
TCOM : Dave Berg/Rivers Rutherford
TBPM : 90
Rip date : 2006-07-13
TRCK : 1/10
Source : CD (LP)
TDRC : 2006-07-18
Ripping tool : EAC
Release type : Normal Release
TLAN : eng
TPE2 : Rodney Atkins
TSSE : Lavf56.19.100
Stream #0:0: Audio: mp3 (libmp3lame), 44100 Hz, stereo, s16p
Metadata:
encoder : Lavc56.20.100 libmp3lame
Stream mapping:
Stream #0:0 -> #0:0 (mp3 (native) -> mp3 (libmp3lame))
Press [q] to stop, [?] for help
[mp3 @ 0x7fd32b827200] overread, skip -8 enddists: -5 -5
[mp3 @ 0x7fd32b827200] overread, skip -5 enddists: -4 -4
[mp3 @ 0x7fd32b827200] overread, skip -5 enddists: -2 -2
[color=#FF0000][mp3 @ 0x7fd32b827200] Header missing
Error while decoding stream #0:0: Invalid data found when processing input
[mp3 @ 0x7fd32b827200] Header missing
Error while decoding stream #0:0: Invalid data found when processing input
[/color]size= 3340kB time=00:03:33.65 bitrate= 128.1kbits/s
video:0kB audio:3338kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.060209%
fifteen:If You're Going Through Hell