Kodi Community Forum

Full Version: Gotham - audio discontinuity when switching tracks
You're currently viewing a stripped down version of our content. View the full version with proper formatting.
Pages: 1 2 3
Following discussion in other multichannel thread yesterday I downloaded a nightly release of openelec with Gotham code.
Great to report that my high-res multichannel FLAC audio files now play through without any problems - thanks for the work guys Big Grin
However, there is a hangover of the problem in Frodo, where the audio sink is being initialised when you manually skip from track to track with the remote skip key or when using the skip key icon in the OSD.
In my case, when I'm playing a six channel SACD rip (88.2kHz) or DVD-Audio rip (96kHz) and I skip to another track, the audio is briefly initialised back to 44.1kHz stereo and then back to the proper sampling rate. My amplifier responds to this by clicking and I can lose a second of audio.
The only way I can change this behaviour is to change the "Output Configuration" in the System / Audio from "Optimised" to a fixed sampling rate. This is not really a practical solution as I have recordings with 44.1, 88.2, 96 and 192kHz sampling rates - although complete albums are obviously at one single rate.
In the attached link to my xbmc log, I first skip through a couple of CD stereo tracks starting at 14:51:58 without issues. At 14:52:27 I start a multichannel version of the same album and skip through several tracks at 30 second intervals. Each time the audio sink is re-initialised and I get a click from the amplifier. At 14:55:03 I navigate to the System Settings menu and fix the sample rate at 88.2kHz and from then on track changes are faultless.

xbmc log on pastebin

edit - I had posted about this issue almost a year ago in Frodo. DDDamian was looking at the issue at the time, but he has not been active on the forum for some months now - http://forum.xbmc.org/showthread.php?tid...pid1258085
I'm bumping this in the hope that @fritsch or @FernetManta might spot before it disappears. I'm assuming that this is something in the paplayer code which is not handling manual track changes properly, but which does handle normal track transitions when it hits EOF.
Your AVR makes click when one track ends and the sink needs to be reinited for 96khz later, when the new track is buffered and loaded. To not cause sink underruns, e.g. to stream noise short packages of silence are sent to the sink. When new file is read, the sink is reponed. This click you hear.

I am not really sure, what we can do in that short "off" between track 1 and track 2, as normally "gapless" saves you. You might try that PR here: https://github.com/FernetMenta/xbmc/comm...da1e6d85e2

I don't really consider this as a bug, as it does like we intended it.

Edit: made my language clearer (at least I hope so).
In order to fix this we would need to up to player API. Currently application closes/reopen player on skip. In turn player release the stream and flushes the engine. It would work if engine was not flushed.
@fritsch - thanks for replying. I'm afraid that I can't quite grasp what you're telling me, or perhaps I have not explained the issue properly in the first place. Huh
The click from the AVR is just a relay switching on/off the extra channels when it detects a change from two channel stereo to multichannel PCM. But the point I'm trying to make is that PAPlayer, if it is playing six channel 88.2kHz PCM audio, should continue this (even as silent data) when you tell it (using the remote) to skip to the next track on the album. Obviously if the next track you skip to is in a different format or sampling rate, then I would expect some interruption to the audio stream, but this problem is happening even when there is no change to the source data format. It's a real nuisance and not what I would expect by design. Here's a snip of a log (hope it's not too big as embedded data!) where I let xbmc play three tracks from an album without touching the remote. PAPlayer seems to handle the transition from one track to another without any re-initialisation of the sink and there is no interruption of the audio. If you look at the log at 15:14:06 you will see it hits EOF of the first track, then it seems to have 25 seconds of buffer and switches to track 2. Then at 15:18:35 it hits EOF on track 2, then has 25 seconds of buffer and switches to track 3. All sounds perfect and no switching of format etc. Contrast that with my previous log where the sink is re-initialised to 44.1kHz stereo every time I use the remote to skip to a different track. I can't think this is a design feature? I appreciate your time on this and can see that you are debating with FernetMenta on github, but I'm not a programmer (at least not since 1978 when I used to program in COBOL) so I can't immediately understand what you're getting at. I will have a more detailed look at the code, but I think PAPlayer is already handling normal track transitions ok (perhaps because of some flag setting which inhibits sink re-initialisation), but is not handling forced track transitions.

Code:
15:08:48 T:140322940094208   DEBUG: CActiveAE::OpenSink - trying to open device ALSA:hdmi:CARD=NVidia,DEV=1
15:08:48 T:140322940094208    INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=NVidia,DEV=1"
15:08:48 T:140322940094208    INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=NVidia,DEV=1,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x08"
15:08:48 T:140322940094208    INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
15:08:48 T:140322940094208    INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
15:08:48 T:140322940094208   DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 680, bufferSize 2720
15:08:48 T:140322940094208   DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 544, bufferSize 2720
15:08:48 T:140322940094208   DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 31 ms
15:08:48 T:140322940094208   DEBUG: CActiveAE::OpenSink - ALSA Initialized:
15:08:48 T:140322940094208   DEBUG:   Output Device : HDA NVidia
15:08:48 T:140322940094208   DEBUG:   Sample Rate   : 88200
15:08:48 T:140322940094208   DEBUG:   Sample Format : AE_FMT_S32NE
15:08:48 T:140322940094208   DEBUG:   Channel Count : 6
15:08:48 T:140322940094208   DEBUG:   Channel Layout: FL,FR,BL,BR,FC,LFE
15:08:48 T:140322940094208   DEBUG:   Frames        : 544
15:08:48 T:140322940094208   DEBUG:   Frame Samples : 3264
15:08:48 T:140322940094208   DEBUG:   Frame Size    : 24
15:08:48 T:140322948486912   DEBUG: DllAvUtilBase: Using libavutil system library
15:08:48 T:140322948486912   DEBUG: DllAvFormat: Using libswresample system library
15:08:48 T:140322948486912   DEBUG: DllAvUtilBase: Using libavutil system library
15:08:48 T:140322948486912   DEBUG: DllAvFormat: Using libswresample system library
15:08:48 T:140322948486912   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
15:08:48 T:140322952853376   DEBUG: Previous line repeats 1 times.
15:08:48 T:140322952853376    INFO: PAPlayer::PrepareStream - Ready
15:08:48 T:140322952853376   DEBUG: PlayFile : OpenFile succeed, play state 1
15:08:48 T:140320540980992  NOTICE: Thread PAPlayer start, auto delete: false
15:08:48 T:140320540980992   DEBUG: PAPlayer::Process - Playback started
15:08:48 T:140320540980992   DEBUG: OnPlayBackStarted : play state was 1, starting 0
15:08:48 T:140322952853376   DEBUG: CGUIInfoManager::SetCurrentSong(/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/01 - Captain Fantastic And The Brown Dirt Cowboy.flac)
15:08:48 T:140322952853376   DEBUG: Loading additional tag info for file /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/01 - Captain Fantastic And The Brown Dirt Cowboy.flac
15:08:48 T:140322952853376   DEBUG: unrecognized XipComment name: PERFORMER
15:08:48 T:140322952853376   DEBUG: unrecognized XipComment name: TOTALTRACKS
15:08:48 T:140322952853376   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
15:08:48 T:140322952853376   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
15:08:48 T:140322952853376   DEBUG: UPnP: Building didl for object '/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/01 - Captain Fantastic And The Brown Dirt Cowboy.flac'
15:08:48 T:140322952853376   DEBUG: LIRC: Update - NEW at 1054644:160 0 KEY_OK_UP devinput (KEY_OK_UP)
15:09:16 T:140320775845632   DEBUG: Thread JobWorker 140320775845632 terminating (autodelete)
15:11:30 T:140320767452928   DEBUG: EPG - UpdateFromScraper - updating EPG for channel 'RTÉ One' from client '1'
15:11:30 T:140320767452928   DEBUG: EPG - UpdateFromScraper - updating EPG for channel 'RTÉ Two' from client '1'
15:11:30 T:140322529068800   DEBUG: CPVRTimers - Update - updating timers
15:11:30 T:140322529068800   DEBUG: PVRTimers - UpdateEntries - updated timer 257 on client 1
15:11:30 T:140322529068800   DEBUG: PVRTimers - UpdateEntries - updated timer 259 on client 1
15:13:47 T:140322952853376   DEBUG: CAnnouncementManager - Announcement: OnScreensaverActivated from xbmc
15:13:47 T:140322952853376   DEBUG: GOT ANNOUNCEMENT, type: 4, from xbmc, message OnScreensaverActivated
15:13:47 T:140322952853376   DEBUG: ------ Window Init () ------
15:14:06 T:140321505650432    INFO: CFileCache::Process - Hit eof.
15:14:28 T:140320540980992   DEBUG: OnQueueNextItem : play state was 2, starting 0
15:14:28 T:140322537461504  NOTICE: Thread JobWorker start, auto delete: true
15:14:28 T:140322537461504   DEBUG: CFileCache::Open - opening </storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac> using cache
15:14:28 T:140322117404416  NOTICE: Thread FileCache start, auto delete: false
15:14:28 T:140322537461504   DEBUG: unrecognized XipComment name: PERFORMER
15:14:28 T:140322537461504   DEBUG: unrecognized XipComment name: TOTALTRACKS
15:14:28 T:140322537461504    INFO: AudioDecoder: File is queued
15:14:29 T:140322537461504    INFO: PAPlayer::PrepareStream - Ready
15:14:33 T:140320540980992   DEBUG: OnPlayBackStarted : play state was 2, starting 0
15:14:33 T:140321505650432   DEBUG: Thread FileCache 140321505650432 terminating
15:14:33 T:140320540980992   DEBUG: PAPlayer::ProcessStreams - Stream Freed
15:14:33 T:140322948486912   DEBUG: CActiveAE::DiscardStream - audio stream deleted
15:14:33 T:140322948486912   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
15:14:33 T:140322952853376   DEBUG: Previous line repeats 1 times.
15:14:33 T:140322952853376   DEBUG: CGUIInfoManager::SetCurrentSong(/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac)
15:14:33 T:140322952853376   DEBUG: Loading additional tag info for file /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac
15:14:33 T:140322952853376   DEBUG: unrecognized XipComment name: PERFORMER
15:14:33 T:140322952853376   DEBUG: unrecognized XipComment name: TOTALTRACKS
15:14:33 T:140322952853376   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
15:14:33 T:140322952853376   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
15:14:33 T:140322952853376   DEBUG: UPnP: Building didl for object '/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac'
15:14:33 T:140322537461504   DEBUG: DoWork - Saving file state for audio item /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/01 - Captain Fantastic And The Brown Dirt Cowboy.flac
15:14:33 T:140322537461504   DEBUG: DoWork - Marking audio item /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/01 - Captain Fantastic And The Brown Dirt Cowboy.flac as listened
15:15:03 T:140322537461504   DEBUG: Thread JobWorker 140322537461504 terminating (autodelete)
15:16:30 T:140322529068800   DEBUG: CPVRTimers - Update - updating timers
15:16:30 T:140322529068800   DEBUG: PVRTimers - UpdateEntries - updated timer 257 on client 1
15:16:30 T:140322529068800   DEBUG: PVRTimers - UpdateEntries - updated timer 259 on client 1
15:18:35 T:140322117404416    INFO: CFileCache::Process - Hit eof.
15:18:55 T:140320540980992   DEBUG: OnQueueNextItem : play state was 2, starting 0
15:18:55 T:140322537461504  NOTICE: Thread JobWorker start, auto delete: true
15:18:55 T:140322537461504   DEBUG: CFileCache::Open - opening </storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/03 - Bitter Fingers.flac> using cache
15:18:55 T:140321505650432  NOTICE: Thread FileCache start, auto delete: false
15:18:55 T:140322537461504   DEBUG: unrecognized XipComment name: PERFORMER
15:18:55 T:140322537461504   DEBUG: unrecognized XipComment name: TOTALTRACKS
15:18:56 T:140322537461504    INFO: AudioDecoder: File is queued
15:18:56 T:140322537461504    INFO: PAPlayer::PrepareStream - Ready
15:19:00 T:140320540980992    INFO: PAPlayer::ProcessStream - Stream Finished
15:19:00 T:140322117404416   DEBUG: Thread FileCache 140322117404416 terminating
15:19:00 T:140320540980992   DEBUG: OnPlayBackStarted : play state was 2, starting 0
15:19:00 T:140322948486912   DEBUG: CActiveAE::DiscardStream - audio stream deleted
15:19:00 T:140320540980992   DEBUG: PAPlayer::ProcessStreams - Stream Freed
15:19:00 T:140322948486912   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
15:19:00 T:140322952853376   DEBUG: Previous line repeats 1 times.
15:19:00 T:140322952853376   DEBUG: CGUIInfoManager::SetCurrentSong(/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/03 - Bitter Fingers.flac)
15:19:00 T:140322952853376   DEBUG: Loading additional tag info for file /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/03 - Bitter Fingers.flac
15:19:00 T:140322952853376   DEBUG: unrecognized XipComment name: PERFORMER
15:19:00 T:140322952853376   DEBUG: unrecognized XipComment name: TOTALTRACKS
15:19:00 T:140322952853376   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
15:19:00 T:140322952853376   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
15:19:00 T:140322952853376   DEBUG: UPnP: Building didl for object '/storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/03 - Bitter Fingers.flac'
15:19:00 T:140322537461504   DEBUG: DoWork - Saving file state for audio item /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac
15:19:00 T:140322537461504   DEBUG: DoWork - Marking audio item /storage/multichannel/Captain Fantastic And The Brown Dirt Cowboy (SACD 5.1)/02 - Tower Of Babel.flac as listened

(2013-12-04, 18:16)FernetMenta Wrote: [ -> ]In order to fix this we would need to up to player API. Currently application closes/reopen player on skip. In turn player release the stream and flushes the engine. It would work if engine was not flushed.

@FernetMenta - Exactly what I thought! The player is doing something different during skip then what it is doing during normal play. I have only seen your reply now after I had pulled a logfile and replied to @fritsch.
I talked about the ActiveAE Engine design. We only do what the player tells us.
(2013-12-05, 00:58)fritsch Wrote: [ -> ]I talked about the ActiveAE Engine design. We only do what the player tells us.

Yes, the AE code seems to be stable and the underlying problem seems to be with the PAPlayer behaviour as pointed out by @FernetMenta, although the effect is felt by the end-user no matter where the problem actually lies. Where next with this issue, though? Is there a necessity for me to make a bug report somewhere or can you devs note the issue for future investigation? Thanks for the comments so far.
The bugreport will land with us anyways, as paplayer is not really maintained. We are currently tracing a problem with some ms offset between audio tracks in paplayer (mostly mp3s). Let's see if something can done here, without the potential to break the established API - paplayer is rather dump, when it comes to track skip ...
I did some investigation on this. The engine is not even flushed but skipping tracks is really slow. Application closes player and it may take longer than a second to open player again and queue the new file. AE is left without anything to play and as we would expect ti switches back to gui sound mode.
Having played through a lot of my SACD collection (which is on my local hard drive) I encountered only one occasion where there was not a seamless transition between tracks of an album when I left it play normally. However I could not reproduce the error later whether or not I had the debug log switched on. So maybe 99.9% of the time no issue with normal track playback. Maybe a timer / flag in AE might hold it in the current sampling / channel configuration while PAPlayer switches tracks? If PAPlayer code is dumb when switching tracks maybe nothing can be done there.
I can certainly test any changes once they filter through to openelec nightlies. Thanks for the investigation guys!
As I explained above: paplayer does not change tracks when skipping. This is done by application which closes/reopens player. I thought about a timer but it will need to hold old configuration for 2-3 secs which is crap when no track follows.
Ok thanks - I see you are referring to the OSD/GUI when you say "application". I could see where this could get very messy.
When saying application I refer to the top level layer of XBMC.
I pushed something to my master. If application is about to open a new file on skip it informs player with a new parameter in close that it should keep the old audio configuration for a while.
Excellent - thanks FernetMenta! I had thought maybe of an additional flag in the "Output Configuration" in the System / Audio settings which would cause the AE to hold configuration a little longer for that minority of users who have multichannel high-res music on their systems. I would think that the vast majority of users would have stereo 44.1kHz audio for music tracks so such a switch would be of little interest to them.
I'll await the trickle down of your change to the openelec nightlies!
Did not work in yesterday's version. I'll do some fixes to it.
Pages: 1 2 3