Making things better

On this week, I fixed architecture mistakes in event registrator. When I've enabled registering of all time events (when somebody whant to know about system ticks) there strange mistakes occurred and it didn't work at all.  So, I've enabled registering time events only in some places of engine. But even in comments to my gsoc proposal, LordHoto noticed that need something to do with it, because when different parts of VM see different time, this will cause problems. In addition, direct replacement of g_system->getMillis() by the g_eventRec.getMillis() is bad, untransparent, unflexible, etc. At last, after one of commits, my mentor _sev proposed me to liquidate this dirty hack, by getting rid of all g_eventRec calls and doing registration of all g_system->getMillis() calls.
First problem we have found - events might be recorded before full initialization of registrator. It was fixed by simple  flag adding which shows that the registrator completely initialized.
After I solved this problem, I tried to find another bugs during at about two days. Something went wrong, but I couldn't find what exactly. _sev very helped me when suggested to use backtrace macros which will show who and when call getMillis fucntion. I've begun to write this data to log and analyze it. This helped me to find next two problems:
DefaultEventManager::pollEvent called more often durring the playback. And also it calls if user doing any action (moves mouse, presses keyboard keys). I solve this programm by adding a stop and start registrating feature  to registrator class. Now it just skips time messages from pollEvent function.
Last problem was hard to find, but very easy to solve. To describe a problem I should tell how we've developed wrapper for audio registering.
Original audio subsystem can be represented by this sequence diagramm:

I. e, SDL audio subsystem give mixer manager to know about it's readiness to play next chunk of sound and give buffer which must be filled by sound data. Manager give this event to platform-independent mixer which must to fill this buffer. Mixer check is there any free chanal and give this buffer to it. Chanal fill the buffer by sound data and ask the current time from system. System ask for time from events registrator.

This scheme worked perfectly, but had a little problem: it was very hard to synchronize sound with logic. Wasn't possible to determine how often will be calback called and what will be buffer size. _sev proposed to get rid of the dependence from  SDLInternals and replace SdlMixerManager to own wrapper. Obviously, there was needed to use some external events source which  will set how frequently mixer's callback will called. Also, this source must have possibility of sinchronization with registrator. We decided to use processMillis for this purposes.   Regarding to this idea, sequence acquired the following form:

Very easy to see that this sequence resulted in an infinite loop and stack overflow. We decied to make a bypass to disable events recording while mixer's callback executing 

Now, in case of necessary, registrator taken out from sequence and system time became the result of function. It saved from stack overflow and worked quite well. When I began to register all calls of getMillis, problem has arisen where I did not expect it. There is function Chanal::getElapsedTime, which returns the time elapsed from begining of sound playing. It getting first time period in Chanal::mix function (during it bypass works and time is real from system). Another time it gets from events recorder. So difference between them is undefined and different for each replay. After problem was found it was very easy to fix it and make result of getElapsedTime function positive and predictable.

What is the use of a book without pictures?

Since the last post I've worked on the screenshots feature. There was few requirements:
1) During the recording process screenshots should record into the same file as other evetns
2) It should be possible to setup period of screenshot recording
3) During the playback process screenshots should read from playback file and compare with current game screen. Best of all it would do using MD5 hash, so it must be recorded with image data.

New recording format

Last 2 weeks I've worked on developing of format for holding recorded gameplay data. Why this needed and how does it work you may read under the cut.

My first success

Hi. Last week was pretty fruitful. I got to work EventRecorder on KYRA engine. Let's describe it in more details.

It has begun

Hi to all. It's not my first record in this blog, but I had no chance to introduce myself in previous posts. In this post I'm going to fix this unfortunate mistake.

My name's Danil. I'm ukrainian student and am studying computer science in university.  You might have guessed on the basis of my project's choice, but just in case I will specify that I really love computer games.

Now about news. Of course, main news is MY GSOC PROPOSAL HAS BEEN ACCEPTED!!! What does it mean in practical plane? In practical plane it mean that during the next 4 month you'll read in this blog how I'm writing "Testing framework for ScummVM". I promise that will do my best to make this blog not very boring to read.

What can I say else? Fortunatelly, in this year Ukraine choosed for EURO2012 soccer champ. Our goverment pay a big attention to this event, therefore my university's exams begins and ends early, so I'm almost pass them and ready to work right now. 

Maybe it's all that I can say in introduction. So see you later in next post after I do some work and be able describe any interesting technical details

Progress at 19'th of April

  I tried to make something workable in time, but it was much harder than expected. So I'll show what I had done for this moment. Sources you can see at this  LINK. There I'll tell how and what I did to realize this idea.

  I've read and criticism of my idea to link events with engine's loop. I've desided that it's realy hard in realization and impossible to make universal for all existing engines. Then I've desided to write every "external" event (with some exceptions), namely mouse's moves and clicks, keyboard's events, calling of delay and getmillis functions.  

  I've quite quickly writtem it, fortunately most of all this was already in existing code. Then I've tested it on SKY engine and everything worked perfect.

  I needed to consolidate success and I've tested gameplay recording on KYRA engine. And there began problems. Events have become different from record very fast and gameplay absolutely different with from recorded. I've begun to find out what's wrong. First of all, I've noticed, then getMillisec and delayMillisec functions called not only by engine. ScummVM (GUI system and something also) call them too. It's giving undefined behavior, cause we don't know what state have scummvm when we began record or replay. So, I've removed global hook of these functions and created method getMillis for EventRecorder class. Engine must call this method if want's to record time event. I've changed all callings of g_system->getMillis to g_eventRec.getMillis. It's become better.

  Then I've noticed dependence of gameplay from audio playback. Following the tested game logic, if user presses mouse button during the speach, speach finishes and mouse event doesn't passes to game. As sound is playing in separate thread - audio playback speed doesn't corresponds to gameplay speed. So I've thought how it's possible to record and playback of audio events and synchronize them with gameplay thread. During the code studying, I've noticed then substitution of arguments of mixCallback function in MixerImpl class affects to audio playback speed. I've inserted my hook code into this function. So audio event's syncronizing with EventRecorder's timer and occurs in same moments of time.

  Unfortunatelly, this didn't solve the problem of incorrect gameplay playback. So, for make debugging easier, I've visualised it. I've inserted debug output to log for every place where event occurs.  Now when I'm recording gameplay, I'm saving log file and comparing it with playback's log file using the diff utility. It allows to easyly detects places where playback events became different from recorded events.

  Using this method I've found that in sound_midi.cpp function g_eventRect.getMillis called by timer handler, which is absolutely independend from engine and is a part of scummvm. It called randomly and make errors during the playback. For this time I've made calling of system getMillis and discrepancy has gone.

  Then I've seen that played back gameplay is absolutely identically to the recorded before the sound begin plays. Since audio playback events begin to diverge. It happens becouse game logic and audio playback executing in different threads. It can be executed random number of gamecode while sound is playing. It makes undefined behavior. I've tryed to syncronize engine thread with audio thread. Now engine wait for finishing of audio playing and only then continues work.

  Now I have problem related to wrong returned time of samples was played by certain chanal. I tryed to solve it in current commit, but think I'll havn't time before choosing of participants. And I had to make this post to show current progress of work.

SKY refactoring

In my first post I've wrote about refactoring of SKY engine. Here I want to describe it in more details what did I mean.