search

phetsims / energy-skate-park-basics

"Energy Skate Park: Basics" is an educational simulation in HTML5, by PhET Interactive Simulations.
http://phet.colorado.edu/en/simulation/energy-skate-park-basics
GNU General Public License v3.0
2 stars 9 forks source link

mirror inputs freezes when track is snipped #380

Closed BryceAG closed 6 years ago

BryceAG commented 7 years ago

When testing mirror inputs for phet-io and in playground mode, the mirrored sim will freeze if you try to separate the track at any joint. Found on Win 10, Mac, Chrome, Firefox, Safari, and Edge.

image

phet-steele commented 7 years ago

Associated error when testing with assertions:

phetioEvents.js?bust=1505840103863:160 Uncaught Error: Assertion failed: mismatched messageIndex, possible start/end mismatch
    at window.assertions.assertFunction (assert.js:22)
    at Object.end (phetioEvents.js?bust=1505840103863:160)
    at SimIFrameAPI.js?bust=1505840103863:284
phet-steele commented 7 years ago

@BryceAG I know you probably made this in a hurry, but please don't forget to reference to the QA issue.

For phetsims/QA/issues/50

samreid commented 7 years ago

In deleteControlPoint, if I comment out track.removeEmitter.emit(); then the problem goes away. Not sure why!

samreid commented 7 years ago

@zepumph and @phet-steele discovered this problem has the same nature as https://github.com/phetsims/phet-io/issues/1143

Our hypothesis is that a node start event is being called, but the node is deleted before the end can be called. Neither of us currently understands what the errant sequence is or what the correct sequence is supposed to be.

We worked around that problem with a setTimeout in https://github.com/phetsims/phet-io/issues/1143 and the same workaround works here too, but it is unclear why it works at all. It seems the setTimeout would just schedule the 'end' event for later on. Maybe so it can finish processing the input event?

@zepumph recommends finer-grained logging messages regarding pushing and popping so we can visualize what is happening here. Then we can determine if there is a better solution or if setTimeout is really appropriate.

samreid commented 7 years ago

@zepumph says it is OK to commit the setTimeout workaround for now, but we shouldn't let that defer us from understanding the deeper problem.

phet-steele commented 7 years ago

@samreid if it means anything, the State wrapper gives this error from simply clicking on a track node, no need to even cut it.

SimIFrameAPI Invocation Error: Error: Impossible set state:
energySkateParkBasics.playgroundScreen.view.trackNode_4.controlPointNode_1.controlPointUI
    at energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130
    at Object.g [as setState] (energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130)
    at TPhETIO.implementation [as setState] (energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130)
    at Object.invoke (energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130)
    at Object.handleSingleInvoke (energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130)
    at Object.handleRequest (energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130)
    at energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130 Error: Impossible set state:
energySkateParkBasics.playgroundScreen.view.trackNode_4.controlPointNode_1.controlPointUI
    at http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:52472
    at Object.g [as setState] (http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:52531)
    at TPhETIO.implementation [as setState] (http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:1421226)
    at Object.invoke (http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:1216383)
    at Object.handleSingleInvoke (http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:1215144)
    at Object.handleRequest (http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:1215620)
    at http://www.colorado.edu/physics/phet/dev/html/energy-skate-park-basics/1.4.0-phetiorc.1/energy-skate-park-basics_en-phetio.html?production&sim=energy-skate-park-basics&relativeSimPath&frameTitle=destination:1130:1216610
samreid commented 7 years ago

I'll move the preceding comment to a new issue--it seems separate.

samreid commented 7 years ago

I added push/pop log statements and saw this:


PUSH: 1713: energySkateParkBasics.playgroundScreen.view.trackNode_4.controlPointNode_2.controlPointUI.deleteButton::fired
    PUSH: 1714: energySkateParkBasics.playgroundScreen.model.tracks::itemRemoved
        PUSH: 1715: energySkateParkBasics.playgroundScreen.model.editButtonEnabledProperty::changed
        POP: 1715
        PUSH: 1716: energySkateParkBasics.playgroundScreen.model.clearButtonEnabledProperty::changed
        POP: 1716
    POP: 1714
    PUSH: 1717: energySkateParkBasics.playgroundScreen.model.track_5.physicalProperty::changed
    POP: 1717
    PUSH: 1718: energySkateParkBasics.playgroundScreen.model.track_5.droppedProperty::changed
    POP: 1718
    PUSH: 1719: energySkateParkBasics.playgroundScreen.model.tracks::itemAdded
        PUSH: 1720: energySkateParkBasics.playgroundScreen.model.clearButtonEnabledProperty::changed
        POP: 1720
    POP: 1719
    PUSH: 1721: phetio::stepSimulation
    POP: 1721
PUSH: 1714: energySkateParkBasics.simIFrameAPI::invoked
POP: 1714
PUSH: 1715: energySkateParkBasics.simIFrameAPI::invoked
    PUSH: 1716: energySkateParkBasics.playgroundScreen.view.trackNode_4.controlPointNode_2.controlPointUI.deleteButton::fired
        PUSH: 1717: energySkateParkBasics.playgroundScreen.model.tracks::itemRemoved
            PUSH: 1718: energySkateParkBasics.playgroundScreen.model.editButtonEnabledProperty::changed
            POP: 1718
            PUSH: 1719: energySkateParkBasics.playgroundScreen.model.clearButtonEnabledProperty::changed
            POP: 1719
        POP: 1717
        PUSH: 1720: energySkateParkBasics.playgroundScreen.model.track_5.physicalProperty::changed
        POP: 1720
        PUSH: 1721: energySkateParkBasics.playgroundScreen.model.track_5.droppedProperty::changed
        POP: 1721
        PUSH: 1722: energySkateParkBasics.playgroundScreen.model.tracks::itemAdded
            PUSH: 1723: energySkateParkBasics.playgroundScreen.model.clearButtonEnabledProperty::changed
            POP: 1723
        POP: 1722
    POP: 1715
Assertion failed: mismatched messageIndex, possible start/end mismatch
    PUSH: 1722: energySkateParkBasics.browserTabVisibleProperty::changed
    POP: 1722
    PUSH: 1724: energySkateParkBasics.browserTabVisibleProperty::changed
    POP: 1724
    PUSH: 1723: energySkateParkBasics.browserTabVisibleProperty::changed
    POP: 1723
    PUSH: 1725: energySkateParkBasics.browserTabVisibleProperty::changed

This confirms that the root of the problem is that controlPointUI.deleteButton::fired pushes but never pops, and it is happening on the source and destination frame.

samreid commented 7 years ago

It looks like PushButtonModel.dispose disposes the endedCallbacksForFiredEmitter, I wonder if that happens while that emitter still has listeners.

samreid commented 7 years ago

It looks like in https://github.com/phetsims/axon/issues/124 we decided that it is OK for Emitters to still have listeners when disposed.

samreid commented 7 years ago

Is it fair to say a button should not be disposed while it is in the process of firing? I added an assertion as such in my working copy.

zepumph commented 7 years ago

In regards to the last time we dealt with this in https://github.com/phetsims/phet-io/issues/1143 (credit due to the master of finding old issues: @phet-steele). We found that the close button was calling hide, but hide was actually disposing the dialog. This was a bug, so we just detached the hide and dispose calls. I don't think that will be too much help here, but maybe. . .

samreid commented 7 years ago

A 4000ms fuzz test on the PhET brand sims did not reveal issues with this assertion, I'll probably commit it. But we should evaluate whether there are other kinds of things that need to not be disposed while they are processing.

zepumph commented 7 years ago

Is it fair to say a button should not be disposed while it is in the process of firing?

I feel like that is a reasonable assumption, maybe we should try to bring this up for dev meeting to see what people think about best practices.

samreid commented 7 years ago

In the preceding commit, you can use ?log to see a detailed PUSH/POP message stream for the phetioEvents to help debug "message index out of order" sort of problems.

samreid commented 7 years ago

I also committed a change to PushButtonModel that it throws an assertion error if it disposes or fires while already firing. Now we need a nice way to address this for Energy Skate Park: Basics.

samreid commented 7 years ago

What if PushButtonModel was using the "single Emitter" paradigm for nesting, see https://github.com/phetsims/phet-io/issues/1203 -- would that fix this problem?

samreid commented 7 years ago

I used setTimeout to avoid disposing a button from its own fire method. @jonathanolson or @pixelzoom can you think of a better way to avoid disposing a button from its own fire method?

zepumph commented 7 years ago

What if PushButtonModel was using the "single Emitter" paradigm for nesting, see phetsims/phet-io#1203 -- would that fix this problem?

I don't know how it would fix it. Wouldn't it still have the same problem because the listener is being attached to the emitter's callbacksEndedEmitter and called later (but it will be disposed before the call)?

Maybe it would be good to talk in person about this.

pixelzoom commented 7 years ago

I used setTimeout to avoid disposing a button from its own fire method.

I'm not clear on why a button can't be disposed of from its own fire method.

jonathanolson commented 7 years ago

I used setTimeout to avoid disposing a button from its own fire method. @jonathanolson or @pixelzoom can you think of a better way to avoid disposing a button from its own fire method?

Please don't use setTimeout, for the reasons it is banned from usage by our code review guidelines. That definitely should be able to screw up sim playback on its own.

I'm not clear on why a button can't be disposed of from its own fire method.

I can guess it's because it would dispose resources that would be used for sending phet-io events.

If this is the case, I'd (a) try to find a way for it to be OK to dispose from its own fire, or (b) figure out how to "queue" disposal if the event is happening, and check for this case (and dispose it) at the end of the event.

samreid commented 7 years ago

I'm not clear on why a button can't be disposed of from its own fire method.

PhET-iO relies on the "finished calling back button fired listeners" callback to close the "transaction". The button was getting disposed during firing callbacks and the transaction was never completing

I'd (a) try to find a way for it to be OK to dispose from its own fire,

Great idea @jonathanolson, perhaps if we detect that a dispose happens during firing, we can close the PhET-iO transaction.

samreid commented 7 years ago

I removed the setTimeout and replaced it with code that completes the PhET-iO transaction, and it is working well. We should apply this strategy in other places with the setTimeout workaround, such as the issue marked above. @zepumph do you know of other places with the setTimeout workaround?

phet-steele commented 7 years ago

@samreid are we going to keep the assertion in https://github.com/phetsims/energy-skate-park-basics/issues/380#issuecomment-330721521 (I don't know if it's still being discussed or not)? It's being thrown in expression-exchange and scenery-phet, and so would need work to fix if we keep the assertion. Should I go ahead and report it?

samreid commented 7 years ago

Yes, I'd like to see how to reproduce the problem in Expression Exchange.

phet-steele commented 7 years ago

Referenced above.

samreid commented 7 years ago

@samreid are we going to keep the assertion in #380 (comment) (I don't know if it's still being discussed or not)?

The assertion was removed in phetsims/sun@3be19b7

zepumph commented 7 years ago

@samreid the solution looks effective, elegant, and simple.

Are there any other places where we want this logic? What other ui components are allowed to dispose themselves while carrying out an event?

zepumph commented 7 years ago

I don't think there are any other places where setTimeout is being used to delay a dispose. We used that only briefly in the about dialog issue above.

samreid commented 7 years ago

Are there any other places where we want this logic?

Perhaps we will find the other problematic cases during PhET-iO testing or fuzz testing (like how Energy Skate Park: Basics crashed). Additionally, in https://github.com/phetsims/phet-info/issues/59 we are discussing a lint rule to forbid setTimeout in sims, so perhaps that will catch other cases that got painted into this corner. Sound OK?

zepumph commented 7 years ago

Sounds great. ready to close?

jessegreenberg commented 6 years ago

@phet-steele mentioned that this issue is probably related to https://github.com/phetsims/energy-skate-park/issues/8.

If I run http://localhost:8080/phet-io-wrappers/wrapper-template/wrapper-template.html?sim=energy-skate-park-basics&ea, pull out a track segment, then cut at the center control point, I see

Assertion failed: mismatched messageIndex, possible start/end mismatch

@zepumph this is the issue we were talking about this afternoon.

samreid commented 6 years ago

I am not seeing this problem in master. https://github.com/phetsims/energy-skate-park-basics/issues/415 made it so that PhET-iO events end properly, even for disposed objects. Closing.