phetsims / gas-properties

"Gas Properties" is an educational simulation in HTML5, by PhET Interactive Simulations.
GNU General Public License v3.0
6 stars 6 forks source link

CT: lightParticles has not been populated yet #178

Closed pixelzoom closed 4 years ago

pixelzoom commented 4 years ago

After fixing #177 (invalid dt: 0) adding all required tandems in #147, these 2 errors are occurring in CT for gas-properties, gases-intro, and diffusion:

gas-properties : phet-io-state-fuzz : require.js : run
Uncaught Error: Assertion failed: lightParticles not been populated yet
Error: Assertion failed: lightParticles not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/assert/js/assert.js?bust=1582585072940:22:13)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/gas-properties/js/common/model/ParticleSystem.js?bust=1582585073103:112:21
    at listener (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/axon/js/DerivedProperty.js?bust=1582585073103:66:35)
    at TinyEmitter.emit (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/axon/js/TinyEmitter.js?bust=1582585073103:68:55)
    at NumberProperty._notifyListeners (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/axon/js/Property.js?bust=1582585073103:279:27)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/axon/js/Property.js?bust=1582585073103:329:49
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/phet-io/js/PhetioStateEngine.js?bust=1582585073103:188:44
    at Array.forEach (<anonymous>)
    at PhetioStateEngine.setState (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/phet-io/js/PhetioStateEngine.js?bust=1582585073103:188:15)
    at PhetioEngineIO.implementation (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/phet-io/js/PhetioEngineIO.js?bust=1582585073103:203:45)
id: Bayes Chrome
Approximately 2/24/2020, 1:48:09 PM

gas-properties : phet-io-state-fuzz : require.js : run
Uncaught Error: Uncaught Error: Assertion failed: mismatched index, possible start/end mismatch
Error: Assertion failed: mismatched index, possible start/end mismatch
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/assert/js/assert.js?bust=1582585072940:22:13)
    at DataStream.end (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/phet-io/js/dataStream.js?bust=1582585073103:270:17)
    at PhetioCommandProcessor.phetioEndEvent (https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/tandem/js/PhetioObject.js?bust=1582585073103:424:32)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582577289634/phet-io/js/phetioCommandProcessor.js?bust=1582585073103:110:20
id: Bayes Chrome
Approximately 2/24/2020, 1:48:09 PM

Description of the phet-io-state-fuzz test in continuous-server.js is:

snapshot.testQueue.push( {
  count: 0,
  snapshotName: snapshotName,
  test: [ phetioRepo, 'phet-io-state-fuzz', 'require.js' ],                    
url: 'sim-test.html?url=' + encodeURIComponent( `../../${snapshotName}/phet-io-wrappers/state/?sim=${phetioRepo}&phetioDebug&fuzz&postMessageToParent` )                      
} );
pixelzoom commented 4 years ago

Here's the relevant code in ParticleSystem.js:

      this.numberOfParticlesProperty = new DerivedProperty(
        [ this.numberOfHeavyParticlesProperty, this.numberOfLightParticlesProperty ],
        ( numberOfHeavyParticles, numberOfLightParticles ) => {

          // Verify that particle arrays have been populated before numberOfParticlesProperty is updated.
          // If you hit these assertions, then you need to add this listener later.  This is a trade-off
          // for using plain old Arrays instead of ObservableArray.
          assert && assert( this.heavyParticles.length === numberOfHeavyParticles,
            'heavyParticles has not been populated yet' );
          assert && assert( this.lightParticles.length === numberOfLightParticles,
            'lightParticles has not been populated yet' );
          return numberOfHeavyParticles + numberOfLightParticles;
        }, 

I'm guessing that this may have something to do with how PhET-iO now restores state.

@zepumph @samreid @chrisklus any thoughts? Is there something about how PhET-iO restores state that is relevant here?

pixelzoom commented 4 years ago

I tried simply commenting out the 2 assertion in the above code:

// assert && assert( this.heavyParticles.length === numberOfHeavyParticles,
//   'heavyParticles has not been populated yet' );
// assert && assert( this.lightParticles.length === numberOfLightParticles,
//   'lightParticles not been populated yet' );

The 2 errors noted by CT go away, but a new error occurs. This one looks like a NumberProperty exceeding its range, not enough of a stack trace to say for sure.

?sim=gas-properties&phetioDebug&fuzz:114 Uncaught Error: Assertion failed: value failed isValidValue: 10330.067349137931
    at window.assertions.assertFunction (assert.js?bust=1582587753937:22)
    at Object.isValueValid (ValidatorDef.js?bust=1582587754221:301)
    at validate (validate.js?bust=1582587754221:30)
    at NumberProperty.Property.validate (Property.js?bust=1582587754221:141)
    at NumberProperty.set (Property.js?bust=1582587754221:170)
    at Function.setValue (PropertyIO.js?bust=1582587754221:119)
    at Function.setValue (NumberPropertyIO.js?bust=1582587754221:79)
    at PhetioStateEngine.setStateForPhetioObject (PhetioStateEngine.js?bust=1582587754221:315)
    at PhetioStateEngine.js?bust=1582587754221:260
    at Array.forEach (<anonymous>)
pixelzoom commented 4 years ago

If I run http://localhost/~cmalley/GitHub/phet-io-wrappers/state/?sim=gas-properties&fuzz, without phetioDebug, then the CT errors go away. What is phetioDebug doing that causes the dependencies of this.numberOfParticlesProperty to notify at a different time?

KatieWoe commented 4 years ago

Noting that this also occurs in diffusion and gasses intro.

@pixelzoom edit: Noted in the description above.

pixelzoom commented 4 years ago

Hmm... This Error is also occurring occasionally:

gas-properties : phet-io-state-fuzz : require.js : run
Uncaught Error: Assertion failed: value failed isValidValue: 13075
Error: Assertion failed: value failed isValidValue: 13075
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/assert/js/assert.js?bust=1582719915372:22:13)
    at Object.isValueValid (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/ValidatorDef.js?bust=1582719915533:301:41)
    at validate (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/validate.js?bust=1582719915533:30:20)
    at NumberProperty.Property.validate (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/Property.js?bust=1582719915533:141:34)
    at NumberProperty.set (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/Property.js?bust=1582719915533:170:31)
    at Function.setValue (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/PropertyIO.js?bust=1582719915533:119:18)
    at Function.setValue (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/axon/js/NumberPropertyIO.js?bust=1582719915533:79:22)
    at PhetioStateEngine.setStateForPhetioObject (https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/phet-io/js/PhetioStateEngine.js?bust=1582719915533:315:31)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582713760956/phet-io/js/PhetioStateEngine.js?bust=1582719915533:260:16
    at Array.forEach (<anonymous>)
id: Bayes Chrome
Approximately 2/26/2020, 3:42:40 AM
gas-properties : phet-io-tests : no-assert
9 out of 9 tests passed. 0 failed.

Approximately 2/26/2020, 3:42:40 AM
pixelzoom commented 4 years ago

And this variation of "has not been populated yet" in diffusion:

diffusion : phet-io-state-fuzz : require.js : run
Uncaught Error: Assertion failed: particles2 has not been populated yet
Error: Assertion failed: particles2 has not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/assert/js/assert.js?bust=1582716161965:22:13)
    at DiffusionModel.numberOfParticlesProperty.DerivedProperty.numberType (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/gas-properties/js/diffusion/model/DiffusionModel.js?bust=1582716162115:108:21)
    at listener (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/DerivedProperty.js?bust=1582716162115:66:35)
    at TinyEmitter.emit (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/TinyEmitter.js?bust=1582716162115:68:55)
    at NumberProperty._notifyListeners (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/Property.js?bust=1582716162115:279:27)
    at NumberProperty.set (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/Property.js?bust=1582716162115:178:16)
    at NumberProperty.set value [as value] (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/Property.js?bust=1582716162115:349:34)
    at DiffusionSettings.restart (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/gas-properties/js/diffusion/model/DiffusionSettings.js?bust=1582716162115:92:44)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/gas-properties/js/diffusion/model/DiffusionModel.js?bust=1582716162115:184:29
    at TinyEmitter.emit (https://bayes.colorado.edu/continuous-testing/snapshot-1582711720255/axon/js/TinyEmitter.js?bust=1582716162115:68:55)
id: Bayes Chrome
Approximately 2/26/2020, 3:08:40 AM
pixelzoom commented 4 years ago

Note that line number for above stack traces have changed, since this was reported before the conversion to ES6 modules.

Here's a new stack trace for gas-properties:

gas-properties : phet-io-state-fuzz : require.js : run
Uncaught Error: Assertion failed: lightParticles has not been populated yet
Error: Assertion failed: lightParticles has not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/assert/js/assert.js?bust=1583857935650:22:13)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/gas-properties/js/common/model/ParticleSystem.js:109:19
    at listener (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/axon/js/DerivedProperty.js:62:33)
    at TinyEmitter.emit (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/axon/js/TinyEmitter.js:65:53)
    at NumberProperty._notifyListeners (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/axon/js/Property.js:276:25)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/axon/js/Property.js:326:47
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/phet-io/js/PhetioStateEngine.js:188:42
    at Array.forEach (<anonymous>)
    at PhetioStateEngine.setState (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/phet-io/js/PhetioStateEngine.js:188:13)
    at PhetioEngineIO.implementation (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/phet-io/js/PhetioEngineIO.js:200:43)
id: Bayes Chrome
Approximately 3/10/2020, 9:33:13 AM

gas-properties : phet-io-state-fuzz : require.js : run
Uncaught Error: Uncaught Error: Assertion failed: mismatched index, possible start/end mismatch
Error: Assertion failed: mismatched index, possible start/end mismatch
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/assert/js/assert.js?bust=1583857935650:22:13)
    at DataStream.end (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/phet-io/js/dataStream.js:267:15)
    at PhetioCommandProcessor.phetioEndEvent (https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/tandem/js/PhetioObject.js:421:30)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583854393245/phet-io/js/phetioCommandProcessor.js:107:18
id: Bayes Chrome
Approximately 3/10/2020, 9:33:13 AM

... and diffusion:

diffusion : phet-io-state-fuzz : require.js : run
Uncaught Error: Assertion failed: particles2 has not been populated yet
Error: Assertion failed: particles2 has not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/assert/js/assert.js?bust=1583848773099:22:13)
    at DiffusionModel.numberOfParticlesProperty.DerivedProperty.numberType (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/gas-properties/js/diffusion/model/DiffusionModel.js:105:19)
    at listener (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/axon/js/DerivedProperty.js:62:33)
    at TinyEmitter.emit (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/axon/js/TinyEmitter.js:65:53)
    at NumberProperty._notifyListeners (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/axon/js/Property.js:276:25)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/axon/js/Property.js:326:47
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/phet-io/js/PhetioStateEngine.js:188:42
    at Array.forEach (<anonymous>)
    at PhetioStateEngine.setState (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/phet-io/js/PhetioStateEngine.js:188:13)
    at PhetioEngineIO.implementation (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/phet-io/js/PhetioEngineIO.js:200:43)
id: Bayes Chrome
Approximately 3/10/2020, 5:05:38 AM

diffusion : phet-io-state-fuzz : require.js : run
Uncaught Error: Uncaught Error: Assertion failed: mismatched index, possible start/end mismatch
Error: Assertion failed: mismatched index, possible start/end mismatch
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/assert/js/assert.js?bust=1583848773099:22:13)
    at DataStream.end (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/phet-io/js/dataStream.js:267:15)
    at PhetioCommandProcessor.phetioEndEvent (https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/tandem/js/PhetioObject.js:421:30)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1583838338979/phet-io/js/phetioCommandProcessor.js:107:18
id: Bayes Chrome
Approximately 3/10/2020, 5:05:38 AM
pixelzoom commented 4 years ago

@samreid helped me with this via Zoom.

From https://github.com/phetsims/gas-properties/issues/178#issuecomment-590607230:

If I run http://localhost/~cmalley/GitHub/phet-io-wrappers/state/?sim=gas-properties&fuzz, without phetioDebug, then the CT errors go away.

This is because phetioDebug automatically adds ea to the URL. That has its own problems, as noted in https://github.com/phetsims/phet-io-wrappers/issues/339, but at least I understand it now.

What is phetioDebug doing that causes the dependencies of this.numberOfParticlesProperty to notify at a different time?

What's happening is that the State wrapper is setting numberOfHeavyParticlesProperty. That updates the this.heavyParticles particles array, then causes this.numberOfParticlesProperty derivation function to fire:

    this.numberOfParticlesProperty = new DerivedProperty(
      [ this.numberOfHeavyParticlesProperty, this.numberOfLightParticlesProperty ],
      ( numberOfHeavyParticles, numberOfLightParticles ) => {

        // Verify that particle arrays have been populated before numberOfParticlesProperty is updated.
        // If you hit these assertions, then you need to add this listener later.  This is a trade-off
        // for using plain old Arrays instead of ObservableArray.
        assert && assert( this.heavyParticles.length === numberOfHeavyParticles,
          'heavyParticles has not been populated yet' );
        assert && assert( this.lightParticles.length === numberOfLightParticles,
          'lightParticles has not been populated yet' );
        return numberOfHeavyParticles + numberOfLightParticles;
     },

Since this.heavyParticles has been populated, the first assertion passes. But since numberOfLightParticles has not been restored yet, the second assertion fails, resulting in the Error message that appears in CT.

pixelzoom commented 4 years ago

In the above commit, the assertions are skipped while state is being restored. This will probably result in other similar downstream errors, but resolves this issue. I leave this open until CT verifies that this Error is not longer occurring.

pixelzoom commented 4 years ago

This issue is resolved in CT.

As predicted, there's a new downstream issue with the State wrapper, tracking in https://github.com/phetsims/gas-properties/issues/181.

pixelzoom commented 4 years ago

Reopening. This same issue needs to be addressed in DiffusionModel.

pixelzoom commented 4 years ago

Addressed in DiffusionModel, closing.

pixelzoom commented 4 years ago

Reopening and removing the workaround that was applied in https://github.com/phetsims/gas-properties/commit/da9220367cc9469707f1494b58f143e64e644bc8.

Like #182, this stems from a more general problem in PhetioStateEngine. @samreid, @chrisklus, and I worked on the general problem via Zoom. See discussion in phetsims/axon#276 (comment). A general solution should be in place before working on this issue.

zepumph commented 4 years ago

Over in https://github.com/phetsims/axon/issues/276 we added support to only apply a DerivedProperty's derivation function once when it is deferred, instead of many times with intermediate values even when it was deferred. This fixed this bug with no changes to sim-specific code. The specific lines are in DerivedProperty where listener is created and added to dependencies, and where setDeferred is overridden. @pixelzoom please confirm fixed and feel free to close.

pixelzoom commented 4 years ago

@zepumph This problem does not appear to be fixed, it still occurring in CT:

gas-properties : phet-io-state-fuzz : require.js : run
https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io-wrappers/state/?sim=gas-properties&phetioDebug&fuzz&postMessageToParent&postMessageOnLoad&postMessageOnError&postMessageOnBeforeUnload
Uncaught Error: Assertion failed: lightParticles has not been populated yet
Error: Assertion failed: lightParticles has not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/assert/js/assert.js:22:13)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/gas-properties/js/common/model/ParticleSystem.js:109:19
    at DerivedProperty.setDeferred (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/axon/js/DerivedProperty.js:147:44)
    at PhaseCallback.listener (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/PhetioStateEngine.js:421:48)
    at attemptToApplyPhase (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/PhetioStateEngine.js:261:27)
    at PhetioStateEngine.undeferAndNotifyProperties (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/PhetioStateEngine.js:281:40)
    at PhetioStateEngine.setState (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/PhetioStateEngine.js:182:10)
    at PhetioEngineIO.implementation (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/PhetioEngineIO.js:200:43)
    at PhetioCommandProcessor.processCommand (https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/phetioCommandProcessor.js:266:51)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1587622935351/phet-io/js/phetioCommandProcessor.js:160:36
id: Bayes Chrome
Approximately 4/23/2020, 12:22:15 AM

I'm also seeing an Error from the first assertion in the Gas Properties listener, which had not previously occurred:

gas-properties : phet-io-state-fuzz : require.js : run
https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io-wrappers/state/?sim=gas-properties&phetioDebug&fuzz&postMessageToParent&postMessageOnLoad&postMessageOnError&postMessageOnBeforeUnload
Uncaught Error: Assertion failed: heavyParticles has not been populated yet
Error: Assertion failed: heavyParticles has not been populated yet
    at window.assertions.assertFunction (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/assert/js/assert.js:22:13)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/gas-properties/js/common/model/ParticleSystem.js:107:19
    at DerivedProperty.setDeferred (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/axon/js/DerivedProperty.js:147:44)
    at PhaseCallback.listener (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/PhetioStateEngine.js:421:48)
    at attemptToApplyPhase (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/PhetioStateEngine.js:261:27)
    at PhetioStateEngine.undeferAndNotifyProperties (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/PhetioStateEngine.js:281:40)
    at PhetioStateEngine.setState (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/PhetioStateEngine.js:182:10)
    at PhetioEngineIO.implementation (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/PhetioEngineIO.js:200:43)
    at PhetioCommandProcessor.processCommand (https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/phetioCommandProcessor.js:266:51)
    at https://bayes.colorado.edu/continuous-testing/snapshot-1587616695796/phet-io/js/phetioCommandProcessor.js:160:36
id: Bayes Chrome
Approximately 4/22/2020, 10:38:15 PM
zepumph commented 4 years ago

At one point last night. This bug was fixed, but then we broke it again because this case isn't fixed in the general case like we originally thought.

In DerivedProperty, we originally were saying that all dependencies should notify before the derivedProperty would undefer. This turned out to create interdependencies, like in MeasuringTapeNode (found via Projectile Motion testing). Thus the best thing to do for this case IMO was to mark out specific order dependencies that make sure that notifications that populate the particle arrays fire before the DerivedProperty tries to recompute. This doesn't feel horrible to me because of the atypical nature of needing a notification before an undefer. In most cases, we found that order depedencies are waiting on an undefer.

If we find that this case is happening a lot, I think it would be good to wrap these calls in a clearer API, but didn't feel too strongly about it just yet.

State fuzzing is working locally so I committed.

@pixelzoom please review changes to ParticleSystem.js.

pixelzoom commented 4 years ago

Change in ParticleSystem.js looks good, I augmented the documentation a little in the above commit. No problems noted in CT, so closing. Thanks @zepumph!