Assertion Errors after migrating from 1.4 to 1.5 when new generation is reached

[Nancy-Salpepi]

Test device MacBook Air M1 chip

Operating System 13.5

Browser Safari 16.6

Problem description For https://github.com/phetsims/qa/issues/967, in the migration wrapper: In version 1.4 if I add a mate, press pause and then press migrate now, pressing play in version 1.5 results in assertion errors popping up repeatedly once" Generation 1" is reached.

Steps to reproduce In the migration wrapper:

1. In version 1.4 press "Add a Mate"
2. Press Pause while still in Generation 0
3. Press Migrate Now button
4. In version 1.5 press Play

EDIT: The errors will appear in version 1.5 when a new generation is reached. For example, if I didn't press "Migrate Now" until the 5th generation, the errors will appear once the 6th generation is reached in version 1.5. They will also appear whether I was in pause or play mode when I pressed "Migrate Now". To see them in the console, you may have to press the red stop sign (safari) or red X (chrome) at the top.

Visuals

EDIT: See https://github.com/phetsims/natural-selection/issues/353#issuecomment-1662711778 for the proper error and stack trace.

[Nancy-Salpepi]

This can be completely unrelated, but if I press Migrate Now, while version 1.4 is paused, the data in the proportions graph is missing. This is not the case for the population graph.

EDIT: I am going to go ahead a make a separate issue for this.

[pixelzoom]

I can't reproduce the error that @Nancy-Salpepi reported in https://github.com/phetsims/natural-selection/issues/353#issue-1831976389.

I see a different error in 1.5 and master when Generation 1 is reached.

In 1.4, the stack trace is obfuscated:

In master, the stack trace is more informative:

This error references ProportionsModel, so that seems related to what @Nancy-Salpepi reported in https://github.com/phetsims/natural-selection/issues/353#issuecomment-1661221820.

[pixelzoom]

@Nancy-Salpepi and I met on Zoom. The "reentry detected" error occurs over and over, and was obscuring the first error that occurs -- which is the "recordEndCounts" error. So we are seeing the same (bad) behavior.

[pixelzoom]

Here's the relevant code in ProportionsModel.ts, where the assertion on line 251 is failing. My guess is that currentStartCountsProperty is not being restored, or has not yet been restored when this method is called (state ordering problem).

     /**
      * Records end counts for the previous generation, using what was formerly the current generation start data.
      */
     public recordEndCounts( generation: number, endCounts: BunnyCounts ): void {
       ...
       const startCounts = this.currentStartCountsProperty.value!;
251    assert && assert( startCounts !== null );
       this.previousCounts.push( new ProportionsCounts( generation, startCounts, endCounts ) );
     }

[pixelzoom]

This problem does not occur in the State wrapper, so it's probably not related to the order that state is restored.

[pixelzoom]

ProportionsModel.ts is defined as follows:

  private readonly currentStartCountsProperty: Property<BunnyCounts | null>;

I have no idea why it's value is null when recordEndCounts is called following migration.

I thought this might have something to do with the changes to BunnyCountsIO, so I reverted https://github.com/phetsims/natural-selection/commit/c7192ec1731bf9b6aec399e1590850dc0c4facb8. But the error still occurs.

I'm stumped. Reaching out to @zepumph and @samreid for assistance. Note that https://github.com/phetsims/natural-selection/issues/354 is also a migration problem with ProportionsModel, and seems related.

[pixelzoom]

ProportionsModel recordEndCounts (the failing method) is called in NaturalSelectionModel.ts, relevant code below.

Note the checks for isSettingPhetioStateProperty.

    // All the stuff that happens at 12:00 on the generation clock.
    // unlink is not necessary.
    this.generationClock.clockGenerationProperty.lazyLink( clockGeneration => {

      // When restoring PhET-iO state, skip this code, because downstream elements are already stateful.
      if ( !isSettingPhetioStateProperty.value ) {

        // Generation 0 is initialized elsewhere, this code is for subsequent generations.
        if ( clockGeneration !== 0 ) {

          phet.log && phet.log( `====== Generation ${clockGeneration} ======` );

          // Before bunnies are aged or mated, Record 'End of Generation' counts for the Proportions graph.
          this.proportionsModel.recordEndCounts( clockGeneration - 1, this.bunnyCollection.getLiveBunnyCounts() );

The assertion in recordEndCounts is failing because currentStartCountsProperty has a null value. currentStartCountsProperty is set via ProportionsModel recordStartCounts, which is called in 2 places by NaturalSelectionModel.ts -- simulationModeProperty listener and generationClock.clockGenerationProperty listener.

[pixelzoom]

I added more info to the assertion failure in recordEndCounts:

    assert && assert( startCounts !== null, `startCounts is null for generation=${generation}` );

The error message reported is now:

Assertion failed: startCounts is null for generation=0

[zepumph]

@pixelzoom and I found it! Looks like currentStartCountsProperty is null after migration, and it is from deleting that from state in a migration rule. Commits from https://github.com/phetsims/natural-selection/issues/344.

Just because something is phetioReadOnly doesn't mean that we don't want it to be stateful.

[pixelzoom]

@zepumph and I both verified the fix, and we want to get this sim into RC ASAP. So I'm going to proceed with creating the release branch and have @Nancy-Salpepi verify this issue in 1.5.0-rc.1, rather than in master.

Please close if this issue verifies OK.

[Nancy-Salpepi]

No more errors in rc.1! Closing!