Author Topic: Another crazy bug discovery  (Read 623 times)

0 Members and 1 Guest are viewing this topic.

Offline Goober5000

  • HLP Loremaster
  • Moderator
  • 214
    • Goober5000 Productions
Another crazy bug discovery
I spent the past week banging my head against the wall trying to determine why chained events in one particular mission didn't work after upgrading them to use the new timestamp system.  It turns out that upgrading the timestamps pulled the rug out from under a gloriously accidental, perfectly constructed house of cards of counterbalanced behavior.

This wasn't as complex as the eight-layer dip bug that affected Transcend, nor as mysterious as the Blue Planet epic bughunt, but it is remarkable for how beautifully the mistakes all fit together.

Here is my writeup from pull request 4633:

Code: [Select]
// This flag is needed because of a remarkable coincidence of mistakes that all counteracted each other perfectly to produce an important feature.
// It appears that originally mission_event.timestamp was in fix units, like satisfied_time and born_on_date.  At some point this was changed to
// a timestamp, but not every assignment was changed.  And since a fix is an int under the hood, there were no type conflicts.  Surprisingly there
// were no logic errors either; the fix/Missiontime assignments happened after the timestamps were needed, and the only places where the timestamp
// field was treated as a fix (here and in sexp_event_delay_status) happened after the event had been resolved and the Missiontime assignments had
// occurred.  The mission_event.timestamp field spent half its life as one unit and half as another, successfully.
//
// The following chaining behavior check typically occurred during the fix/Missiontime part of the life cycle.  However, for chained events that
// repeat, the event is granted a new timestamp and the chain check is performed on mixed units.  Due to the way the condition was written, the
// much-too-small comparison evaluated to false successfully and allowed the event subsequent to the chained repeating event to become current.
// This is the behavior necessary to allow the "Match Speed 1 1/2" event in btm-01.fsm to activate, display the "Match Speed" directive, and
// continue with the mission.  Without this behavior, the mission would break.
//
// Naturally, upgrading the timestamps caused all evaluations to use consistent units and broke the mission.  Due to the long repeat interval, the
// timestamp was evaluated too late when the event was likely to have become false.  The previous mixed-units comparison avoided the repeat interval
// precisely at the right time, and then became consistent units when the repeat interval no longer mattered.  In order to restore the expected
// behavior while keeping all units consistent, it is necessary to set a flag when a timestamp includes an interval so that the interval can be
// deducted from the period of time that evaluation is bypassed.

 

Offline Galemp

  • Actual father of Samus
  • 212
  • Ask me about GORT!
    • Steam
    • User page on the FreeSpace Wiki
Re: Another crazy bug discovery
I only understood every other word of that but good job fixing it :yes:
"Anyone can do any amount of work, provided it isn't the work he's supposed to be doing at that moment." -- Robert Benchley

Members I've personally met: RedStreblo, Goober5000, Sandwich, Splinter, Su-tehp, Hippo, CP5670, Terran Emperor, Karajorma, Dekker, McCall, Admiral Wolf, mxlm, RedSniper, Stealth, Black Wolf...