AppleTV 2 (black) - Frodo MP3 playback issues (@ 5 seconds before end)

  Thread Rating:
  • 0 Votes - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
Post Reply
Basje Offline
Skilled Python Coder
Posts: 1,052
Joined: Jul 2005
Reputation: 6
Post: #1
With the most recent monthly build (Alpha 5) I am having issues playing MP3 files. All files have a hick-up about 5 seconds before the end. From the logfile I can see that at that moment the caching of the next track starts (this track had a duration of 1m05s and starts at 17:00:41:

Code:
17:00:41 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track01., fd=10001
17:00:41 T:124583936   DEBUG: CSmbFile::Close closing fd 10001
17:00:41 T:124583936   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
17:00:41 T:124583936   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
17:00:41 T:98234368    INFO: CFileCache::Process - Hit eof.
17:00:44 T:124583936   DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-arm-osx.so)
17:00:44 T:124583936   DEBUG: Unloading: ImageLib-arm-osx.so
17:01:11 T:124583936   DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/libid3tag-arm-osx.so)
17:01:11 T:124583936   DEBUG: Unloading: libid3tag-arm-osx.so
17:01:28 T:1053969640   DEBUG: XBMCPureController: Button press remoteAction = 6
17:01:28 T:124583936   DEBUG: CWinEventsIOS: Button press keyID = 3
17:01:28 T:1053969640   DEBUG: XBMCPureController: Button press remoteAction = 6
17:01:28 T:1053969640   DEBUG: XBMCPureController: Button press remoteAction = 3
17:01:28 T:124583936   DEBUG: CWinEventsIOS: Button press keyID = 1
17:01:29 T:1053969640   DEBUG: XBMCPureController: Button press remoteAction = 3
17:01:29 T:1053969640   DEBUG: XBMCPureController: Button press remoteAction = 5
17:01:29 T:124583936   DEBUG: CWinEventsIOS: Button press keyID = 5
17:01:29 T:124583936   DEBUG: ExecuteXBMCAction : Translating fullscreen
17:01:29 T:124583936   DEBUG: ExecuteXBMCAction : To fullscreen
17:01:29 T:124583936   DEBUG: Activating window ID: 12006
17:01:29 T:124583936   DEBUG: ------ Window Deinit (MyMusicNav.xml) ------
17:01:29 T:124583936   DEBUG: ------ Window Init (MusicVisualisation.xml) ------
17:01:29 T:124583936    INFO: Loading skin file: MusicVisualisation.xml
17:01:40 T:124583936   DEBUG: CFileCache::Open - opening <3/15/246.mp3> using cache
17:01:40 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10001
17:01:40 T:124583936   DEBUG: DllLibApeTag: Using libapetag library
17:01:40 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:40 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:40 T:124583936   DEBUG: SECTION:LoadDLL(special://xbmcbin/system/libid3tag-arm-osx.so)
17:01:40 T:124583936   DEBUG: Loading: /private/var/stash/Applications/XBMC.frappliance/XBMCData/XBMCHome/system/libid3tag-arm-osx.so
17:01:40 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:40 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:40 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:40 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:40 T:124583936   DEBUG: DllLibApeTag: Using libapetag library
17:01:40 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:40 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:41 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:41 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:41 T:124583936   DEBUG: CSmbFile::Open - opened Albums/Album 01/Track02.mp3, fd=10002
17:01:41 T:124583936   DEBUG: CSmbFile::Close closing fd 10002
17:01:41 T:124583936    INFO: AudioDecoder: File is queued
17:01:41 T:124583936    INFO: CCoreAudioAE::MakeStream - AE_FMT_S32NE, 44100, 0, FL,FR
17:01:41 T:124583936   DEBUG: CCoreAudioUnit::RemoveRenderProc: Remove RenderProc 0x02d0bd59 for unit 0x102b5c60.
17:01:41 T:124583936   ERROR: CCoreAudioUnit::Close: Unable to disconnect AudioUnit. Error = -10860
17:01:41 T:124583936   DEBUG: CCoreAudioUnit::RemoveRenderProc: Remove RenderProc 0x02d0bd59 for unit 0x0e4edaf0.
17:01:41 T:124583936   ERROR: CCoreAudioUnit::Close: Unable to disconnect AudioUnit. Error = -10860
17:01:41 T:124583936   ERROR: Previous line repeats 1 times.
17:01:41 T:124583936    INFO: CCoreAudioAEHALIOS::Deinitialize: Audio device has been closed.
17:01:41 T:124583936    INFO: CCoreAudioAE::Deinitialize: Audio device has been closed.
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Input Stream Format  [lpcm] Mixable Non-Interleaved 2 Channel 32-bit Signed Integer LE (44100Hz)
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Output Stream Format [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Input Stream Format  [lpcm] Mixable Non-Interleaved 2 Channel 32-bit Signed Integer LE (44100Hz)
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Output Stream Format [lpcm] Mixable Non-Interleaved 2 Channel 32-bit Signed Integer LE (44100Hz)
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Input Stream Format  [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (44100Hz)
17:01:41 T:124583936    INFO: CCoreAudioGraph::Open: Output Stream Format [lpcm] Mixable Non-Interleaved 2 Channel 32-bit Signed Integer LE (44100Hz)
17:01:41 T:124583936   DEBUG: CCoreAudioUnit::SetRenderProc: Set RenderProc 0x02d0bd59 for unit 0x1026c670.
17:01:41 T:124583936    INFO: CCoreAudioAE::Initialize:
17:01:41 T:124583936    INFO:   Output Device :
17:01:41 T:124583936    INFO:   Sample Rate   : 44100
17:01:41 T:124583936    INFO:   Sample Format : AE_FMT_FLOAT
17:01:41 T:124583936    INFO:   Channel Count : 2
17:01:41 T:124583936    INFO:   Channel Layout: FL,FR
17:01:41 T:124583936    INFO:   Frame Size    : 8
17:01:41 T:124583936    INFO:   Volume Level  : 1.000000
17:01:41 T:124583936    INFO:   Passthrough   : 0

I did not have this issue with Alpha 4. Any suggestions?

(This post was last modified: 2012-09-11 17:28 by Basje.)
find quote
Memphiz Offline
Team-XBMC Developer
Posts: 10,158
Joined: Feb 2011
Reputation: 109
Location: germany
Post: #2
Please retry again with alpha4 for a confirmation. imo this is a known issue on osx/ios with the new audio engine - and i doubt that it was better with alpha4.

AppleTV2/iPhone/iPod: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for XBMC: Wiki NFS
HowTo configure avahi (zeroconf): Wiki Avahi
READ THE IOS FAQ!: iOS FAQ
find quote
Basje Offline
Skilled Python Coder
Posts: 1,052
Joined: Jul 2005
Reputation: 6
Post: #3
(2012-09-11 23:29)Memphiz Wrote:  Please retry again with alpha4 for a confirmation. imo this is a known issue on osx/ios with the new audio engine - and i doubt that it was better with alpha4.

I am 99.9% sure that I did not have this with alpha4, I listen to a lot of music and never had this....until I upgraded to alpha5. To take my network out of the equation I even tried data stored on my ATV2 locally (so no network) same issue. But if there is an easy way of downgrading I could try that, but I don't want to loose all my settings/databases and so. I already have a hard time getting my database (shared between XBMC @ Windows, ATV2 and Android) synced with the correct database version.

What would be a correct and safe way to go back to Alpha 4 test and then go back without loosing any stuff?

EDIT: Perhaps somebody that is still on Alpha 4 can test?
(This post was last modified: 2012-09-11 23:46 by Basje.)
find quote
Memphiz Offline
Team-XBMC Developer
Posts: 10,158
Joined: Feb 2011
Reputation: 109
Location: germany
Post: #4
Well i'm 100% sure that nobody changed anything in the audioengine between a4 and a5. An i know where the blipp comes from. This code is in there since ae was merged in may.

AppleTV2/iPhone/iPod: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for XBMC: Wiki NFS
HowTo configure avahi (zeroconf): Wiki Avahi
READ THE IOS FAQ!: iOS FAQ
find quote
Basje Offline
Skilled Python Coder
Posts: 1,052
Joined: Jul 2005
Reputation: 6
Post: #5
(2012-09-12 10:14)Memphiz Wrote:  Well i'm 100% sure that nobody changed anything in the audioengine between a4 and a5. An i know where the blipp comes from. This code is in there since ae was merged in may.

Ok, then perhaps somebody can tell me how to go back to A4 so I can test?

find quote
Ned Scott Offline
Team-XBMC Wiki Guy
Posts: 18,346
Joined: Jan 2011
Reputation: 221
Location: Arizona, USA
Post: #6
You should be able to just install that specific deb file as you would for a normal nightly or monthly on iOS (instructions should be mentioned on those links). You might want to backup your userdata folder (see iOS FAQ for specific location and some methods of backing up) just in case, but it should be able to work by just slapping the Alpha 4 build on top of the Alpha 5 build and vise versa.

You can make easy links to the XBMC wiki using double brackets around words: [[debug log]] = debug log, [[Add-on:YouTube]] = Add-on:YouTube, [[Adding videos to the library]] = Adding videos to the library, [[userdata]] = userdata, etc
find quote
freshmikeb Offline
Junior Member
Posts: 48
Joined: Sep 2011
Reputation: 0
Location: Los Angeles
Post: #7
This problem has existed on all versions of Frodo to date.

Is it a CPU bottleneck? Multiple processes are happening at once - playing current track, prefetch next track at 5 sec left, start crossfade at 3 sec left (in my case), finish fetch of next track and then BLIP and continue play. Other than the quick BLIP cutout, playback and crossfade is working pretty well.

Would prefetching the next track earlier than 5 sec left help?
find quote
Basje Offline
Skilled Python Coder
Posts: 1,052
Joined: Jul 2005
Reputation: 6
Post: #8
I, apparently was indeed wrong: the ATV2 A4 was released only half way of August, so I probably used A3 for most of that month.

But, the big question is, will this issue be solved in a near future? I am very freakish (so yes, it's my problem) about my audio and really get annoyed by the split second halt in audio.

find quote
Memphiz Offline
Team-XBMC Developer
Posts: 10,158
Joined: Feb 2011
Reputation: 109
Location: germany
Post: #9
Its not a cpu bottleneck. Its a locking issue of the streams. Will it be solved in the near future? Who knows. I didn't find a way to fix it yet and got already bored about it...

AppleTV2/iPhone/iPod: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for XBMC: Wiki NFS
HowTo configure avahi (zeroconf): Wiki Avahi
READ THE IOS FAQ!: iOS FAQ
find quote
Memphiz Offline
Team-XBMC Developer
Posts: 10,158
Joined: Feb 2011
Reputation: 109
Location: germany
Post: #10
Its solved in current nightly builds.

AppleTV2/iPhone/iPod: HowTo find debug logs and everything else which the devs like so much: click here
HowTo setup NFS for XBMC: Wiki NFS
HowTo configure avahi (zeroconf): Wiki Avahi
READ THE IOS FAQ!: iOS FAQ
find quote
Basje Offline
Skilled Python Coder
Posts: 1,052
Joined: Jul 2005
Reputation: 6
Post: #11
(2014-02-24 14:13)Memphiz Wrote:  Its solved in current nightly builds.

Nice! Thanks for that.

find quote