Saturday, December 18, 2021

Ludricous Speed

 There's another bug with my modified version of libntxm. It has been around since at least early School Rush prototypes and possibly even Apple Assault. If you let the player spin for too long, it suddenly starts to play things at ridiculous speed that makes the song barely recognizable.

I had the Dreams demo running with ARM7 debugger plugged in for another reason (undefined instruction) and it started speeding the song up so I dropped all my kitchen stuff and jumped on the CTRL+C to be able to dig that later. And later is now.

One symptom of the issue seems to be that the tick_ms variable is now way larger than the MsPerTick() property of the Song.

Every time the playTimeHandler() is invoked, it recomputes how many milliseconds elapsed since last call, and here I get the value of 1. It won't get out of the issue because there's nowhere we could read tick_ms = 0. Instead, the amount of time expected is substracted from the time elapsed so far, so that 'extra milliseconds' are deduced from the next 'tick'.But watching that tick_ms evolve, it is properly decreasing. It has not just been gone wild. It got corrupted from something else.

It doesn't tell me what goes wrong in the soft, unfortunately, but at least, it gives me a way to make sure players won't experience it. If I cap the tick_ms to 2*MsPerTick(), I shouldn't have issues.

Note how buggy tick_ms is close to last_ms ...

Note how unlikely it is that the player has been running for 43509 seconds. I wasn't even running it for one hour! And when it eventually occured again, lastms was 43494543, or something alike (decimal, not hexa).

Seeing some more code featuring 'compute over 100' now makes much more sense. 100 times higher than 43 million, we're quite at MAXINT for an unsigned. Plus, if you've got an unsigned, comparing -t to something might very well produce something that is compiler-dependent. Likely, there might be a switch to produce a warning for that.

Il y a un truc qui me chagrinait, avec School Rush: au bout d'un certain temps la musique partait en vrille. Le problème se posait uniquement au bout d'un temps assez long, du coup, je n'avais jamais eu l'occasion de prendre le temps de chercher le problème. Mais hier, j'avais un débuggeur ARM7 prêt à fonctionner, un émulateur branché dessus avec le code qui 'là-normalement-ça-devrait-marcher' pour un autre soucis et j'étais en cuisine ... donc ils ont tourné pendant longtemps sans intervention ... assez longtemps pour que le problème de School Rush se produise. J'ai bondi sur mon ordi pour interrompre tout ça et débugguer enfin cette histoire.

Au premier tour, tout ce que j'ai pu dire c'est que "bin c'est parce que tout d'un coup, on découvre qu'on est en retard de plus de 40 millions de microsecondes pour passer au 'tic' de musique suivant". J'avais espéré qu'il s'agissait d'une déviation ou quelque-chose de ce genre, j'avais mis quelques 'break if...' dans ddd mais quand le problème s'était finalement re-reproduit (bonne journée, ça), on était passé de quelques millisecondes de retard à plus de 43 millions, comme ça, sans-transition-à-vous-les-studios. J'en venais à me dire que 'tant pis, je vais juste mettre un patch qui limite artificiellement ce délai' puis je tombe sur l'implémentation de la lecture du temps à partir du hardware qui cache une division par 100 ... et 100 * 43 million, on approche du plus grand entier 32 bits. Là, ça pue le bug de conversions arithmétique dû à une soustraction mal calibrée... ça je pourrai corriger pour de bon.

No comments: