Saturday, September 30, 2023

Un p'tit coup de marteau ...

Mes dernières sessions avec AnimEDS s'étaient toutes soldées par des "guru meditation". Peu de travail perdu, heureusement, le problème se produisant généralement soit juste au début, soit juste après une sauvegarde. L'impact sur ma motivation à continuer à animer mes p'tits persos en prenait quand-même chaque fois un coup: j'aurais pu effectivement perdre un travail précieux.

Alors j'ai noté de faire du debugging de tout ça. Il y a un bail. D'abord refaire une version précise de l'animateur (rH2021) et garder le .nds et son .elf à côté des fichiers re-générés à tout bout de champ quand je bricole du homebrew, histoire que quand le problème se présente console en main, je puisse effectivement utiliser la valeur du registre PC pour retrouver un numéro de ligne dans le code. C'est le cas depuis Juin.

I can't help wondering whether this is worth translating. It's another epic (?) showdown between me and my code to see who's got the StrongARM. But well, it has been bugging me since January, crashing the animation editor almost every time I used it. I'm just lucky I never lost anything important but motivation to work on some cute things over the evening. The "guru meditation" screens I got during the first half of the year were almost useless: the AnimEDS build on my 'lime' DS was so old I did not have the matching .ELF file for my debugger anymore. Believe it or not, the RealLife (tm) has turned so intense that I even had to write down an agenda check list with "rebuild ; keep .elf apart ; upload .nds to lime" to actually get it done.

Pas de chance: c'est un de ces bugs où l'adresse ne dit pas grand-chose parce qu'on est a suivi des pointeurs de fonctions qui ne voulaient rien dire. Mais! Bonne nouvelle, avec les nouvelles animations pour l'Appleman, le bug est plus facile à reproduire: il suffit d'essayer de copier une frame d'animation juste après avoir chargé la première animation du fichier dans l'éditeur.

Alors j'ai ressorti mon émulateur et mon débuggeur et là, bonne nouvelle, ça foire aussi dans l'émulateur. Différemment, mais ça foire, donc c'est débuggable. Et là, j'ai galéré pendant des heures ... Des structures qui ne veulent rien dire, des vptr complètement à l'ouest ... Il faut dire que pour encoder la ligne du temps utilisée par l'éditeur, j'ai pris une std::list de std::pair de classe dérivées. Bref, on se perd sous les couches de templates, de membres dépendant de l'implémentation et d'optimisation du compilateur qui prend un malin plaisir à rendre inaccessible les variables dont on aurait besoin.

With that done, I wasn't much more lucky. It's one of those bugs where you try doing a virtual function call on something that isn't truly an object and thus end up in the middle of nowhere, especially where memory contents doesn't match any valid opcode. Hopefully, while trying to get the crash to write down registers values, I realised that the bug was actually easy to reproduce (just open one animation and try to copy the frame before selecting any frame) and a bit later, that it also happened with the same file in my emulator. At least I could save the evening where I navigate DS memory to reconstruct objects on paper this time.

J'allais jeter le gant puis un soir j'ai noté dans mon calepin "fait du débugging indirect en surveillant les constructeurs". Bah oui: la variable aura beau avoir été optimisée, il faut bien qu'il soit construit à un moment où à un autre, le TIFrame qui explique pourquoi j'ai du n'importe quoi dans les registres au moment de copier cette première frame.

Sauf que ... non. Les "TIFrames" sont construites vides, puis au fur et à mesure que l'AnimationParser traite la liste de commandes destinées à GEDS -- le moteur de jeu -- il complète les coordonnées, les numéros d'images, etc. J'étais sur le point de laisser tomber (traduire: réécrire tout avec ma propre classe 'liste' plus propice au debugging) quand je réalise que je peux "figer" l'afficher d'une ou de TIFrame dont je capture l'adresse à la construction, et suivre leur évolution jusqu'au bug (l'animation en question ne contient en réalité qu'une frame et une commande de contrôle). Et là, surprise, tout va très bien (Mme la Marquise :)

 It did not save navigating memory altogether though. The way gdb handles std::list and std::pair combined to the amount of variables that were actually "optimized away" when they would be critical to have around still turned that debugging session into some guru meditation. I first thought that it was because of some incoherent animation instructions into the animation itself, but inspecting how the animationParser processed them shown everything should be fine. Yet, if I tried to see what frame was triggering the bug, all I'd get was garbage non-sense. I was about to replace all that std::* by some pype::* when I realised that I could just break on constructors of the contained TimeItems to see what the list contained.

That did not work either, unfortunately, because when TimeItems are added to the list, they are "blank" items that will be modified by the yet-to-come UPDATE animation commands. What did help, was creating some static watches at addresses discovered in a constructor-breakpoints so that I could look at the state of my list just before the offending call. That and realising that the list was just fine, thanks, but that I was using an iterator that might not have been updated since the previous list had been trashed and replaced by the new one :P

Une seule explication restante: c'est l'itérateur qui devient invalide au bout d'un moment. Je sors mon cahier A4 histoire de me faire une map UML de tous les bouts de code impliqués et c'est bien ça: quand on choisit une animation à éditer, la liste est vidée, mais l'itérateur reste inchangé, ce qui est invalide.

Ah oui. Vous vous demandez "pourquoi le marteau" ... et vous n'avez pas Thor. C'est à cause de cette blague d'ingénieur où un consultant rentre une facture de $100000 pour une intervention et ça rouspète chez le client parce que "vous avez juste donné un coup de marteau!". Et le consultant de reconnaître qu'il a fait une erreur et de préparer la facture suivante

  • 1 hammer hit: $10
  • knowing where to hit $99990

(bon, c'était vraiment une grosse machine très chère qu'il fallait dépanner). Bin c'est un peu la sensation que ça me fait sur ce bug-ci. Sauf que je ne vais pas recevoir des cents et des mille et que je ne devrai pas les débourser non plus :P

 

2 comments:

Cyborg Jeff said...

Oui, on dira qu'ici ton cout horaire pour trouver le problème était lui aussi assez élevé ;)

PypeBros said...

l'horaire est lui-même marteau ... Au final, j'y ai passé au plus 2 jours, mais dilué à un niveau quasi-homéopathique :P