search

phetsims / calculus-grapher

"Calculus Grapher" is an educational simulation in HTML5, by PhET Interactive Simulations.
GNU General Public License v3.0
4 stars 4 forks source link

CT both Studio frames did not load in 60000ms #337

Closed KatieWoe closed 11 months ago

KatieWoe commented 11 months ago 
calculus-grapher : migration : 1.0->main : assert
http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/?sim=calculus-grapher&oldVersion=1.0&phetioMigrationReport=assert&locales=*&phetioDebug=true&phetioWrapperDebug=true&fuzz&migrationRate=5000&&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D
Assertion failed: both Studio frames did not load in 60000ms
Error: Assertion failed: both Studio frames did not load in 60000ms
at window.assertions.assertFunction (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/assert/js/assert.js:28:13)
at <unknown> (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/migration.js:196:15)
[URL] http://128.138.93.172/continuous-testing/aqua/html/wrapper-test.html?url=..%2F..%2Fct-snapshots%2F1703212188749%2Fphet-io-wrappers%2Fmigration%2F%3Fsim%3Dcalculus-grapher%26oldVersion%3D1.0%26phetioMigrationReport%3Dassert%26locales%3D*%26phetioDebug%3Dtrue%26phetioWrapperDebug%3Dtrue%26fuzz%26migrationRate%3D5000%26&duration=80000&testInfo=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D
[NAVIGATED] http://128.138.93.172/continuous-testing/aqua/html/wrapper-test.html?url=..%2F..%2Fct-snapshots%2F1703212188749%2Fphet-io-wrappers%2Fmigration%2F%3Fsim%3Dcalculus-grapher%26oldVersion%3D1.0%26phetioMigrationReport%3Dassert%26locales%3D*%26phetioDebug%3Dtrue%26phetioWrapperDebug%3Dtrue%26fuzz%26migrationRate%3D5000%26&duration=80000&testInfo=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D
[NAVIGATED] about:blank
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/?sim=calculus-grapher&oldVersion=1.0&phetioMigrationReport=assert&locales=*&phetioDebug=true&phetioWrapperDebug=true&fuzz&migrationRate=5000&&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D
[NAVIGATED] about:blank
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/studio/?sim=calculus-grapher&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D&phetioMigrationReport=assert&fuzz&locales=*
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] about:blank
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/calculus-grapher/calculus-grapher_en.html?brand=phet-io&ea&debugger&postMessageOnError&sim=calculus-grapher&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D&phetioMigrationReport=assert&fuzz&locales=*&phetioEmitAPIBaseline&phetioCreateArchetypes&phetioEmitHighFrequencyEvents=false
[CONSOLE] enabling assert
[NAVIGATED] https://phet-io.colorado.edu/sims/calculus-grapher/1.0/wrappers/studio/?phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D&phetioMigrationReport=assert&fuzz&exposeStandardPhetioWrapper
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] https://phet-io.colorado.edu/sims/calculus-grapher/1.0/calculus-grapher_all_phet-io_debug.html?ea&postMessageOnError&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22assert%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213204113%7D&phetioMigrationReport=assert&fuzz&exposeStandardPhetioWrapper&phetioEmitAPIBaseline&phetioCreateArchetypes&phetioEmitHighFrequencyEvents=false
[CONSOLE] enabling assert
[CONSOLE] Assertion failed: both Studio frames did not load in 60000ms
[PAGE ERROR] Error: Error: Assertion failed: both Studio frames did not load in 60000ms
at window.assertions.assertFunction (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/assert/js/assert.js:28:13)
at http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/migration.js:196:15
[CONSOLE] continuous-test-wrapper-error
[CONSOLE] continuous-test-wrapper-load

id: "Sparky Node Puppeteer"
Snapshot from 12/21/2023, 7:29:48 PM

----------------------------------

calculus-grapher : migration : 1.0->main : dev
http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/?sim=calculus-grapher&oldVersion=1.0&phetioMigrationReport=dev&locales=*&phetioDebug=true&phetioWrapperDebug=true&fuzz&migrationRate=5000&&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D
Assertion failed: both Studio frames did not load in 60000ms
Error: Assertion failed: both Studio frames did not load in 60000ms
at window.assertions.assertFunction (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/assert/js/assert.js:28:13)
at <unknown> (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/migration.js:196:15)
[URL] http://128.138.93.172/continuous-testing/aqua/html/wrapper-test.html?url=..%2F..%2Fct-snapshots%2F1703212188749%2Fphet-io-wrappers%2Fmigration%2F%3Fsim%3Dcalculus-grapher%26oldVersion%3D1.0%26phetioMigrationReport%3Ddev%26locales%3D*%26phetioDebug%3Dtrue%26phetioWrapperDebug%3Dtrue%26fuzz%26migrationRate%3D5000%26&duration=80000&testInfo=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D
[NAVIGATED] http://128.138.93.172/continuous-testing/aqua/html/wrapper-test.html?url=..%2F..%2Fct-snapshots%2F1703212188749%2Fphet-io-wrappers%2Fmigration%2F%3Fsim%3Dcalculus-grapher%26oldVersion%3D1.0%26phetioMigrationReport%3Ddev%26locales%3D*%26phetioDebug%3Dtrue%26phetioWrapperDebug%3Dtrue%26fuzz%26migrationRate%3D5000%26&duration=80000&testInfo=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D
[NAVIGATED] about:blank
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/?sim=calculus-grapher&oldVersion=1.0&phetioMigrationReport=dev&locales=*&phetioDebug=true&phetioWrapperDebug=true&fuzz&migrationRate=5000&&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D
[NAVIGATED] about:blank
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/studio/?sim=calculus-grapher&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D&phetioMigrationReport=dev&fuzz&locales=*
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] about:blank
[NAVIGATED] http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/calculus-grapher/calculus-grapher_en.html?brand=phet-io&ea&debugger&postMessageOnError&sim=calculus-grapher&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D&phetioMigrationReport=dev&fuzz&locales=*&phetioEmitAPIBaseline&phetioCreateArchetypes&phetioEmitHighFrequencyEvents=false
[CONSOLE] enabling assert
[NAVIGATED] https://phet-io.colorado.edu/sims/calculus-grapher/1.0/wrappers/studio/?phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D&phetioMigrationReport=dev&fuzz&exposeStandardPhetioWrapper
[NAVIGATED] about:blank
[CONSOLE] enabling assert
[NAVIGATED] https://phet-io.colorado.edu/sims/calculus-grapher/1.0/calculus-grapher_all_phet-io_debug.html?ea&postMessageOnError&phetioWrapperDebug=true&wrapperContinuousTest=%7B%22test%22%3A%5B%22calculus-grapher%22%2C%22migration%22%2C%221.0-%3Emain%22%2C%22dev%22%5D%2C%22snapshotName%22%3A%22snapshot-1703212188749%22%2C%22timestamp%22%3A1703213105512%7D&phetioMigrationReport=dev&fuzz&exposeStandardPhetioWrapper&phetioEmitAPIBaseline&phetioCreateArchetypes&phetioEmitHighFrequencyEvents=false
[CONSOLE] enabling assert
[CONSOLE] Assertion failed: both Studio frames did not load in 60000ms
[PAGE ERROR] Error: Error: Assertion failed: both Studio frames did not load in 60000ms
at window.assertions.assertFunction (http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/assert/js/assert.js:28:13)
at http://128.138.93.172/continuous-testing/ct-snapshots/1703212188749/phet-io-wrappers/migration/migration.js:196:15
[CONSOLE] continuous-test-wrapper-error
[CONSOLE] continuous-test-wrapper-load

id: "Sparky Node Puppeteer"
Snapshot from 12/21/2023, 7:29:48 PM
pixelzoom commented 11 months ago

This appears to be happening on every CT cycle, and I doubt that it's sim specific. Let's ask @zepumph.

zepumph commented 11 months ago

Interesting! I have a lot of thoughts, but none of them seem to be making sense while I investigate. I originally thought that the "cause" of this may be from a bug fix I made yesterday in https://github.com/phetsims/aqua/issues/197. This would have exposed errors that were being hidden during page load for CT puppeteer testing. That doesn't seem related so far.

I cannot reproduce the issue testing with puppeteer locally.

I also wondered if I missed CG during the MR to make sure the old sim is set up to send standard wrappers for migration. That doesn't seem like a problem either.

Maybe https://github.com/phetsims/calculus-grapher/issues/338 is related, but I feel like that would show up louder than this.

Generally, I don't think this is a timeout problem, since I would expect that to be intermittent as puppeteer and sparky loads change throughout the day. This is consistent, so I believe that the timeout is downstream of the problem.

I added some logging and I will check back in on CT later.

zepumph commented 11 months ago

Maybe I was just overthinking this, and CG was having trouble loading in 60 seconds normally. I boosted the timeout to 2 minutes and it seems to have fixed it. Likely the bug fix over in https://github.com/phetsims/aqua/issues/197 was the cause of seeing the trouble more often, if you go back in CT before I committed https://github.com/phetsims/aqua/commit/f32879edf7a34931f25816f6e141a90a76843df2, most of that row is empty, as if it didn't test, but I think it was buggy, and wasn't reporting the failure. I'll remove the logging and confirm fixed in a couple of rows.

zepumph commented 11 months ago

Looks clear. Closing