Sounds get mixed up

pra

08-03-2008 21:40:51

I encountered a strange problem today: if I create and destroy a lot of sounds in a relatively short time, they get mixed up, i.e. instead of foo.wav bar.ogg is played.

For testing, I have two weapons that shoot different missiles, there is a sound played as soon as I shoot, the missile has another sound attached to it, and when it hits something, a third one is played. the first sound is created when I need it, and stopped and destroyed as soon as i need a new shooting sound. the second one is created along with it's missile and is destroyed as soon as the missile hits something or after a certain time. the third sound is created then needed and destroyed when finished playing.
I also have a sound for the player's footsteps, it is created once and stopped when not needed.
Everything works fine when I start the app, but after some shooting around i suddenly have one of the fireing sounds for footsteps, or a hit sound is looped as a missile is flying, and similar random confusion...

I create the sounds like this:
int i = 0;
String name = filename;
while(soundMgr->hasSound(name))
{
name = filename+str(i++);
}
OgreAL::Sound *res = soundMgr->createSound(name,filename,loop,stream);


I updated OgreAL about one hour ago from SVN

pra

09-03-2008 15:43:55

even if i can't be sure if this could be somehow related to the above mentioned problem or even to ogreal at all, at least it seems to occur around the time when a new sound is created:



it seems to occur completely random, sometimes it shows up soon after start, sometimes it takes some time, sometimes it does not at all

clicking retry makes it break at mRoot->startRendering();

pra

09-03-2008 19:15:39

update: i just made the app log several member variables of OgreAL::Sound:
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: === printing sound '"+getName()+"' ===");
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mFileName = "+mFileName);
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mSource = "+StringConverter::toString(mSource));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mBuffers = "+ptrToString(mBuffers));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mNumBuffers = "+StringConverter::toString(mNumBuffers));
for(int i=0;i<mNumBuffers;i++)
{
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mBuffers[i] = "+StringConverter::toString(mBuffers[i]));
}
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mBufferSize = "+StringConverter::toString(mBufferSize));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mStream = "+StringConverter::toString(mStream));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mBuffersLoaded = "+StringConverter::toString(mBuffersLoaded));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: mBuffersQueued = "+StringConverter::toString(mBuffersQueued));
Ogre::LogManager::getSingletonPtr()->logMessage("PRA: === sound printing finished ===");

(this much because i had no idea what is important)
mBuffers seems to be the sound's buffer (i forgot to convert i to string there, but mNumBuffers is always 1 anyways)

so it says this when it loads my first hit sound:
19:53:25: PRA: === printing sound 'arrow_impact.wav' ===
19:53:25: PRA: mFileName = arrow_impact.wav
19:53:25: PRA: mSource = 146416944
19:53:25: PRA: mBuffers = 8543900
19:53:25: PRA: mNumBuffers = 1
19:53:25: PRA: mBuffers[i] = 146472576
19:53:25: PRA: mBufferSize = 11024
19:53:25: PRA: mStream = false
19:53:25: PRA: mBuffersLoaded = true
19:53:25: PRA: mBuffersQueued = false
19:53:25: PRA: === sound printing finished ===

so then I searched for "mBuffers = 146472576" in the log. most of it was arrow_impact.wav, but then I found this:

=== printing sound 'fire.ogg10' ===
19:53:52: PRA: mFileName = fire.ogg
19:53:52: PRA: mSource = 146416944
19:53:52: PRA: mBuffers = 857e8c8
19:53:52: PRA: mNumBuffers = 1
19:53:52: PRA: mBuffers[i] = 146472576
19:53:52: PRA: mBufferSize = 5494
19:53:52: PRA: mStream = false
19:53:52: PRA: mBuffersLoaded = true
19:53:52: PRA: mBuffersQueued = false
19:53:52: PRA: === sound printing finished ===

so it seems OgreAL confuses the files sometimes, seems like it occurs when lots of sounds are created and destroyed in a short period of time.
there are more occurrences of the fire.ogg with the same mBuffers, and of other sound files, too, but this is the only one with the same mSource, and the first time where the confusion happens. Does it mean something?

reptor

09-03-2008 21:34:18

Just an idea... maybe some std container iterator gets confused inside OgreAL... I didn't look into it but maybe it could be something like that. Like if the OgreAL deletes one item from a container, and an iterator is pointing to a location in the container, and it does not change the index it points to, but what is pointed at gets changed because one item was deleted. Is this possible? I saw that OgreAL has a vector and a map for the sounds.

Sorry I don't know if I'm on the right track here, as I didn't read the source extensively-enough. I could be completely wrong.

pra

09-03-2008 22:59:20

i have no idea... i just looked at OgreAL's code and now i'm even more confused...
but I might have found a bug:
SoundList::iterator soundItr = mSoundsToDestroy.begin();
while(!mSoundsToDestroy.empty())
{
destroySound(*soundItr);
soundItr = mSoundsToDestroy.erase(soundItr);
}

void SoundManager::destroySound(const Ogre::String& name)
{
// Lock Mutex
OGREAL_LOCK_AUTO_MUTEX

SoundMap::iterator soundItr = mSoundMap.find(name);
if(soundItr != mSoundMap.end())
{
mSoundsToDestroy.push_back(soundItr->second);
mSoundMap.erase(soundItr);
}
}

how can this ever delete a sound? if it is in mSoundMap, then it's removed from there and added to mSoundsToDestroy. then, in the next frame, destroySound is called again, but now the sound isn't in mSoundMap anymore, so nothing happens, it's just erased from mSoundsToDestroy...

or am i alerady to tired to think? its almost 0:00 here...

CaseyB

10-03-2008 04:06:19

No, you are correct! This is a bug! I'll fix it and commit in a couple of minutes!

-=EDIT=-
Ok, it's in!

pra

10-03-2008 10:19:11

ok, but it hasn't fixed the issue with mixed up sounds :(

edit: now i found something interesting!
I added some logging lines in several places in ogreAL:
if(bufferItr != mBufferMap.end())
{
Ogre::LogManager::getSingletonPtr()->logMessage("TEST: :Buffer "+fileName+" alerady exists: "+
Ogre::StringConverter::toString((BufferRef)bufferItr->second));
// We have this buffer loaded already!
return new Sound((BufferRef)bufferItr->second, name, fileName, loop);
}

=>
11:47:53: TEST: :Buffer default_step.wav alerady exists: 154278560
11:47:53: PRA: creating sound in Missile constructor:
11:47:53: PRA: === printing sound 'default_step.wav12' ===
11:47:53: PRA: mFileName = default_step.wav
11:47:53: PRA: mSource = 154144704
11:47:53: PRA: mBuffers = 8584068
11:47:53: PRA: mNumBuffers = 1
11:47:53: PRA: mBuffers = 146420544
11:47:53: PRA: mBufferSize = 11024
11:47:53: PRA: mStream = false
11:47:53: PRA: mBuffersLoaded = true
11:47:53: PRA: mBuffersQueued = false
11:47:53: PRA: === sound printing finished ===

It seems to find the right buffer and pass it to the sound constructor, but then something happens...

edit2: the stuff is printed after sound->play() is called. let's see if i add one before, too

edit3:
the buffers get changed somewhere here:
if(!mBuffersQueued)
{
// Unqueue any buffers that may be left over
unqueueBuffers();
queueBuffers();
}


edit4: seems to be unqueueBuffers()'s fault

pra

10-03-2008 12:12:35

ok, with my PHP debug technique, i could track it down to
alSourceUnqueueBuffers(mSource, queued, mBuffers);
in
void Sound::unqueueBuffers()
before that line, the buffer is ok, and after that the sound has a different one.
I tested it this way:
void Sound::unqueueBuffers()
{
/*
** If the sound doens't have a state yet it causes an
** error when you try to unqueue the buffers! :S In
** order to get around this we stop the source even if
** it wasn't playing.
*/
Ogre::LogManager::getSingletonPtr()->logMessage("TEST 1: buffer="+Ogre::StringConverter::toString(mBuffers[0]));
alSourceStop(mSource);
CheckError(alGetError(), "Failed to stop sound");
Ogre::LogManager::getSingletonPtr()->logMessage("TEST 2: buffer="+Ogre::StringConverter::toString(mBuffers[0]));
int queued;
alGetSourcei(mSource, AL_BUFFERS_QUEUED, &queued);
CheckError(alGetError(), "Failed to get Source");
Ogre::LogManager::getSingletonPtr()->logMessage("TEST 3: buffer="+Ogre::StringConverter::toString(mBuffers[0]));
alSourceUnqueueBuffers(mSource, queued, mBuffers);
CheckError(alGetError(), "Failed to unqueue Buffers");
Ogre::LogManager::getSingletonPtr()->logMessage("TEST 4: buffer="+Ogre::StringConverter::toString(mBuffers[0]));

mBuffersQueued = false;
}

with the output:
13:05:43: TEST 1: buffer=153242256
13:05:43: TEST 2: buffer=153242256
13:05:43: TEST 3: buffer=153242256
13:05:43: TEST 4: buffer=153142744


edit: I just made a workaround:
OgreAL::BufferRef test1 = mBuffers[0];
alSourceUnqueueBuffers(mSource, queued, mBuffers);
if(test1 != mBuffers[0])
{
Ogre::LogManager::getSingletonPtr()->logMessage("It happened again: old="+Ogre::StringConverter::toString(test1)+", new="+Ogre::StringConverter::toString(mBuffers[0]));
mBuffers[0] = test1;
}

it seems to work (although the first time i ran it I got the error from post 2... still no idea how to reproduce it....)

pra

11-03-2008 12:50:16

what should I do now? make a better workaround and submit it?
or is this a bug of OpenAL or even of my hardware?

CaseyB

11-03-2008 14:01:03

Yeah, you can submit a patch. Even if it is an issue with OpenAL or your hardware making the code more robust is never a bad thing.

pra

11-03-2008 16:15:03

i was hoping you would also post HOW to submit a patch, since i can't find it :oops:

well, here is my edited version of unqueueBuffers from the OgreALSound.cpp:
void Sound::unqueueBuffers()
{
/*
** If the sound doens't have a state yet it causes an
** error when you try to unqueue the buffers! :S In
** order to get around this we stop the source even if
** it wasn't playing.
*/
alSourceStop(mSource);
CheckError(alGetError(), "Failed to stop sound");

int queued;
alGetSourcei(mSource, AL_BUFFERS_QUEUED, &queued);
CheckError(alGetError(), "Failed to get Source");

//backupping buffers...
BufferRef *mBufferBak = new BufferRef[mNumBuffers];
for(int i=0;i<mNumBuffers;i++)
{
mBufferBak[i] = mBuffers[i];
}
alSourceUnqueueBuffers(mSource, queued, mBuffers);
//restoring backup...
for(int i=0;i<mNumBuffers;i++)
{
mBuffers[i] = mBufferBak[i];
}
delete mBufferBak;
CheckError(alGetError(), "Failed to unqueue Buffers");


mBuffersQueued = false;
}

CaseyB

11-03-2008 16:52:20

Sure, I'll do a write up, but really all you need to do is right click on the OgreAL folder and go to TortoiseSVN->Create Patch and that will take care of it for you. For now though I can use what you posted here! Thanks!

pra

11-03-2008 17:57:51

will it automatically upload the patch?
with cvs, i had to create a patch and then go upload it manually

CaseyB

11-03-2008 18:10:16

Oh, no, just post the contents of the patch here on the forum if you like, or yo can use the bug tracker on Sourceforge and it will work exactly like it did with Ogre.

pra

11-03-2008 18:21:30

it was the sourceforge bugtracker that i was not able to find, but well, i think next time i'll just post the patch contents^^

CaseyB

11-03-2008 19:32:17

[u]OgreAL Bug Tracker[/u]

dudeabot

01-07-2008 13:56:12

i have this bug too

maybe these bugs are related in some way:

http://www.ogre3d.org/phpBB2addons/view ... ht=unqueue
?

stickymango

01-07-2008 15:46:31

I think theres a bug in the sortLowToHigh() and sortHighToLow() functions at least try this change and report back if it cures the problem:
if(sound2->isRelativeToListener())
{
distSound2 = sound1->getPosition().length();
}
else
{
distSound2 = sound2->getDerivedPosition().distance(listenerPos);
}

to:
if(sound2->isRelativeToListener())
{
distSound2 = sound2->getPosition().length();
}
else
{
distSound2 = sound2->getDerivedPosition().distance(listenerPos);
}