Strange issue with music.

[hikaricore]

Using svn rev 17065 I've notice a very odd issue with music playback.

The playback timer is going at roughly twice the speed it should be,
if crossfading is enabled the song is trunicated, however if it is disabled
it plays fine into the next tracks timer. The next song plays at the end
of the first until it's (still fast) timer runs out then music playback ends.

It's been a week or so since I've built from svn so I can't place the exact time this issue popped up.

Running on Ubuntu 8.10 32bit.

Nothing odd in the log that I can see.

[hikaricore]

23:42:47 T:3052099392 M:116158464 NOTICE: Mapping drive Q to /opt/share/xbmc
23:42:47 T:3052099392 M:116158464 NOTICE: Mapping drive T to /opt/share/xbmc/userdata
23:42:47 T:3052099392 M:116158464 NOTICE: Mapping drive U to /opt/share/xbmc
23:42:47 T:3052099392 M:116158464 NOTICE: -----------------------------------------------------------------------
23:42:47 T:3052099392 M:116158464 NOTICE: Starting XBMC, Platform: GNU/Linux. Built on Jan 13 2009 (SVN:17065)
23:42:47 T:3052099392 M:116158464 NOTICE: Q is mapped to: /opt/share/xbmc
23:42:47 T:3052099392 M:116158464 NOTICE: The executable running is: /opt/share/xbmc/xbmc.bin
23:42:47 T:3052099392 M:116158464 NOTICE: Log File is located: /opt/share/xbmc/xbmc.log
23:42:47 T:3052099392 M:116158464 NOTICE: -----------------------------------------------------------------------
23:42:47 T:3052099392 M:115879936 NOTICE: Setup SDL
23:42:48 T:3052099392 M:114712576 NOTICE: Enabled Joystick: Saitek P990 Dual Analog Pad
23:42:48 T:3052099392 M:114712576 NOTICE: Enabled Joystick: Saitek P990 Dual Analog Pad
23:42:48 T:3052099392 M:114712576 NOTICE: load settings...
23:42:48 T:3052099392 M:114712576 NOTICE: Mapping drive P to /opt/share/xbmc/userdata
23:42:48 T:3052099392 M:114712576 NOTICE: loading /opt/share/xbmc/userdata/guisettings.xml
23:42:48 T:3052099392 M:114601984 NOTICE: Getting hardware information now...
23:42:48 T:3052099392 M:114601984 NOTICE: Checking resolution 12
23:42:48 T:3052099392 M:114601984 NOTICE: No advancedsettings.xml to load (/opt/share/xbmc/userdata/advancedsettings.xml)
23:42:48 T:3052099392 M:114601984 NOTICE: Default Video Player: dvdplayer
23:42:48 T:3052099392 M:114601984 NOTICE: Default Audio Player: paplayer
23:42:48 T:3052099392 M:114601984 NOTICE: /opt/share/xbmc/userdata/sources.xml
23:42:48 T:3052099392 M:114601984 WARNING: CXRandR::SetMode: found alternative mode (same hz): default mode: 0x142.
23:42:48 T:3052099392 M:105746432 WARNING: CreateFile, successfuly opened </opt/share/xbmc/media/Splash.png> instead of </opt/share/xbmc/media/splash.png>
23:42:48 T:3052099392 M:105230336 NOTICE: start dvd mediatype detection
23:42:48 T:3052099392 M:105230336 NOTICE: initializing playlistplayer
23:42:48 T:3052099392 M:105230336 NOTICE: DONE initializing playlistplayer
23:42:48 T:3052099392 M:105230336 NOTICE: load default skin:[Horizonz.III]
23:42:48 T:3052099392 M:102166528 WARNING: file doesnt have <fontset> with name 'Default', defaulting to first fontset
23:42:48 T:3052099392 M:101888000 ERROR: Couldn't load font name:sysinfo file:/opt/share/xbmc/media/Fonts/ocr.ttf
23:42:48 T:3052099392 M:101888000 ERROR: Couldn't load font name:osdsmall file:/opt/share/xbmc/media/Fonts/ocr.ttf
23:42:48 T:3052099392 M:101679104 ERROR: Couldn't load font name:osdbig file:/opt/share/xbmc/media/Fonts/ocr.ttf
23:42:48 T:3052099392 M:100356096 NOTICE: Updating video library on startup
23:42:48 T:3052099392 M: 99856384 NOTICE: HAL: Generating global device list
23:42:48 T:3052099392 M: 99856384 NOTICE: LFS: Added - disk | Volume (ext3)
23:42:48 T:3052099392 M: 99856384 NOTICE: LFS: Added - disk | Volume (ext3)
23:42:48 T:3052099392 M: 99856384 NOTICE: LFS: Added - disk | Volume (ext3)
23:42:48 T:3052099392 M: 99160064 NOTICE: LFS: Added - disk | Volume (ext3)
23:42:48 T:3052099392 M: 97349632 NOTICE: LFS: Added - disk | Volume (swap)
23:42:48 T:3052099392 M: 98951168 NOTICE: LFS: Added - disk | Volume
23:42:48 T:3052099392 M: 98951168 NOTICE: LFS: Added - disk | Volume (ext3)
23:42:48 T:3052099392 M: 97210368 NOTICE: Updating music library on startup
23:42:48 T:3052099392 M: 96952320 NOTICE: initialize done
23:42:48 T:3052099392 M: 96808960 NOTICE: Running the application...
23:42:49 T:3052099392 M: 93298688 NOTICE: Webserver: Starting...
23:42:49 T:2939161488 M: 93229056 NOTICE: Webserver: Started
23:42:49 T:2947554192 M: 92811264 NOTICE: -->Python Interpreter Initialized<--
23:42:49 T:2947554192 M: 92811264 NOTICE:
23:42:49 T:3052099392 M: 92811264 NOTICE: ES: Starting event server
23:42:49 T:2930768784 M: 92811264 NOTICE: ES: Starting UDP Event server on 127.0.0.1:9777
23:42:49 T:2930768784 M: 92811264 NOTICE: UDP: Listening on port 9777
23:42:49 T:2922376080 M: 83648512 NOTICE: AudioScrobbler: Handshake successful.
23:42:55 T:3052099392 M: 84275200 ERROR: Error evaluating boolean expression Control.IsVisible(50) + Container.OnPrevious + [Window.IsVisible(500) | Window.IsVisible(502) + [Window.IsVisible(501) | Container.Content(files)]
23:43:05 T:2997861264 M: 76242944 NOTICE: My Videos: Scanning for video info using worker thread, operation took 00:17
23:43:40 T:2532305808 M: 82141184 ERROR: Recv failed: 115
23:43:40 T:2532305808 M: 82141184 ERROR: FindArtistinfo: Unable to retrieve web site
23:44:43 T:2493492112 M: 80465920 ERROR: Recv failed: 115
23:44:43 T:2493492112 M: 80465920 ERROR: FindArtistinfo: Unable to retrieve web site
23:45:13 T:2922376080 M: 77697024 ERROR: AudioScrobbler: Submission failed: Plugin bug: Not all request variables are set - got 2 parameters.
23:45:14 T:2881481616 M: 81801216 ERROR: Recv failed: 115
23:45:14 T:2881481616 M: 81801216 ERROR: FindArtistinfo: Unable to retrieve web site
23:45:23 T:2821114768 M: 87756800 ERROR: Recv failed: 115
23:45:23 T:2821114768 M: 87756800 ERROR: FindArtistinfo: Unable to retrieve web site
23:46:23 T:2432654224 M: 90451968 ERROR: Recv failed: 115
23:46:23 T:2432654224 M: 90451968 ERROR: FindArtistinfo: Unable to retrieve web site
23:46:58 T:2432654224 M: 84860928 ERROR: Recv failed: 115
23:46:58 T:2432654224 M: 84860928 ERROR: FindArtistinfo: Unable to retrieve web site
23:47:25 T:2432654224 M: 83845120 ERROR: Recv failed: 115
23:47:25 T:2432654224 M: 83845120 ERROR: FindArtistinfo: Unable to retrieve web site
23:47:36 T:2432654224 M: 86061056 ERROR: Recv failed: 115
23:47:36 T:2432654224 M: 86061056 ERROR: FindArtistinfo: Unable to retrieve web site
.

[blittan]

try and make a new build, if problem exists do another debuglog and paste to pastebin.ca

[hikaricore]

I did another build while I was posting and the issue persists.

I rebuild again without the disable debug in my build script (forgot this time :p) and let you know what happens.

[hikaricore]

Same deal on the new build.
I compiled with debug enabled.

Opened xbmc, played one track and let it cut itself off then exited.

Here's the log: http://pastebin.ca/1307848

I poked around in the log file but didn't see anything too odd looking.

[althekiller]

Can you try with pulseaudio disabled? "pulseaudio -k" then run xbmc. I don't have pulse installed and I do not see this problem.

[hikaricore]

*edit*

Ok I was wrong, it's not doing it without pulseaudio running.
At least that narrows it down to svn commits dealing with pulse right?

Also to be clear this is only with audio files, video files have no problems.

[althekiller]

Can you pastebin a debug log w/ pulse disabled?

[hikaricore]

Do you need it with debug enabled or is a straight log fine?
lol I recompiled again with debug disabled to test something

rebuilding again isn't a problem it'll take me like 5 minutes I just wanna post the right log

[hikaricore]

Here's without pulse and with debug on:

http://pastebin.ca/1307876

I've also reverted back to my previous build to check the svn number which is r16861.
Figured I'd post the last version I was using incase that helps track down the issue.

Hopefully it's not just me with this issue. ^_^

[olympia]

I always wanted to raise this question, mybe this is a good place/ time for that.

Do we have any drawback without pulseaudio?

[topfs2]

Could you provide a log with this patch: http://paste.ubuntu.com/104753/

download as text into a file, foo, inside XBMC and do
patch -p0 < foo

or if you want you can add the lines with ++ into xbmc/cores/paplayer/paplayer_linux.cpp

edit: also please do a distclean and ./configure && make and so on

[topfs2]

I always wanted to raise this question, mybe this is a good place/ time for that.

Do we have any drawback without pulseaudio?

Never a good place to hijack a thread but Im answering it anyways ;), passthrough aint working in pulseaudio.

EDIT: missread your question. advantages with pulseaudio are: http://xbmc.org/topfs2/2009/01/09/pulseaudio-and-xbmc-for-linux/

[olympia]

Never a good place to hijack a thread but Im answering it anyways ;), passthrough aint working in pulseaudio.

EDIT: missread your question. advantages with pulseaudio are: http://xbmc.org/topfs2/2009/01/09/pulseaudio-and-xbmc-for-linux/

Thank you Topfs2.
The reason why I thought it's not a hijack is to know why we are forcing pulseaudio, if "everything" works fine with ALSA, but now I have a bit better understanding. Thanks again!

[hikaricore]

Ubuntu has been using pulseaudio exclusively for the last two releases.
That's as good of a reason as any to have pulse in the xbmc code imho.

I'm compiling with that patch right now, I'll post when I've tested it out.

[hikaricore]

Here's the pastebin from the patched xbmc:

http://pastebin.ca/1307921

The time issue is still present and I did notice something in the log content.
XBMC is reporting the next song being played in the log when in actuality it was never started.
I don't know if that helps at all but I thought it warranted a mention.

[topfs2]

Just to be sure

Only happens with pulse running
With all music?
Not with movies?
Context menu on music and select DVDPlayer will make music work?


Because Im unable to reproduce, but if it is only happening to certain files then providing a sample would be most helpfull.

[hikaricore]

Just to be sure

Only happens with pulse running - correct
With all music? - correct
Not with movies? - correct
Context menu on music and select DVDPlayer will make music work? - playing music with dvdplayer works fine, so it's something that has changed in the paplayer since my last compile


Because Im unable to reproduce, but if it is only happening to certain files then providing a sample would be most helpfull.

I've played all of these files with the revision I listed before with no troubles.
Very odd indeed I was hoping I'd find that aleast a few other people were having this issue. >.<

Like I said before I'll just keep building from the svn and see what happens.
As a long time user of WINE and other constantly update projects I'm very comfortable with regressions, this one was just a little bizarre.

Is there currently a way to make dvdplayer default for audio? I can use this as a workaround for the time being,
if need be I can just select it from the context menu which I have mapped to a button on my remotes.

[topfs2]

<advancedsettings>
<audio>
<defaultplayer>dvdplayer</defaultplayer>
</audio>
</advancedsettings>

Should make dvdplayer as default, http://xbmc.org/wiki/?title=Advancedsettings.xml

In anycase, Ill look through the revisions you supplied and try to narrow it down on the information you sent me, my guess is my latest commit were I added a pcmBuffer to make new paplayer work on win32 aswell, will check through my coding so its correct.

Cheers,
Tobias

[hikaricore]

Thank you much for the tip. ^_^

[topfs2]

I still havent been able to completely reproduce this but while fixing another thing in paplayer I stumpled upon a file that might have introduced this behaviour and fixed the issues with that one.
So please try out r17093 or any later

Cheers,
Tobias

[hikaricore]

I'm compiling 17113 right at this moment.
Hope I can inform you of good news. :)

[hikaricore]

It does indeed seem to be fixed. Thanks for your continued assistance. =D

[topfs2]

Glad to hear that it worked, if you get any more issues with paplayer (its currently going through alot of fixes to support multiple audio outputs, as pulseaudio) please post about them!

Cheers,
Tobias