Don't create custom elements in main and fix various small issues on tests

[FabioRosado]

This PR fixes a few things:

• the 'in undefined' error that we have seen when running tests
• the flakiness of the reply tests
• the test_panel_stream tests (cannot read properties of undefined)
• wait a short time to allow the loaded script to be inserted into head

Hopefully, you don't mind this wall of text, explaining the reasoning behind the decisions in the PR 😄

runAfterRuntimeInitialized running immediately on page load

After adding a bunch of console.traces I've noticed that runAfterRuntimeInitialized was being called from main.js which was a bit odd, following the code path, it seems that it was being run when we were creating the py-button custom element in const xPyButton = customElements.define('py-button', PyButton); See the console output for a better visual.

Console output with traces

adding initializer 
async function mountElements()
stores.ts:22:12
added initializer 
async function mountElements()
stores.ts:24:12
adding post initializer 
async function initHandlers()
stores.ts:27:12
added post initializer 
async function initHandlers()
stores.ts:29:12
RUNTIME READY pyenv.ts:8:12
initializers set runtime.ts:9:12
post initializers set runtime.ts:14:12
scripts queue set 2 runtime.ts:19:12
connected pyscript.ts:56:16
console.trace() inside runAfterRuntime base.ts:170:16
    runAfterRuntimeInitialized base.ts:170
    connectedCallback pybutton.ts:57
    <anonymous> main.ts:18
    <anonymous> pyscript.js:27234
console.trace() pyconfig constructor pyconfig.ts:22:16
    PyConfig pyconfig.ts:22
    createElement hello_world.html:1
    <anonymous> main.ts:28
    <anonymous> pyscript.js:27234
console.trace() pyconfig connected callback pyconfig.ts:27:16
    connectedCallback pyconfig.ts:27
    <anonymous> main.ts:29
    <anonymous> pyscript.js:27234
Uncaught TypeError: right-hand side of 'in' should be an object, got undefined
    runAfterRuntimeInitialized base.ts:172
    subscribe index.mjs:50
    runAfterRuntimeInitialized base.ts:171
    connectedCallback pybutton.ts:57
    <anonymous> main.ts:18
    <anonymous> pyscript.js:27234
base.ts:172:16
config set! runtime.ts:27:16
config set 
Object { autoclose_loader: true, runtimes: (1) […] }
pyconfig.ts:41:16
Initializing runtimes... pyconfig.ts:53:16
console.trace() pyodide.ts:40:16
    loadInterpreter pyodide.ts:40
    initialize runtime.ts:55
    loadRuntimes pyconfig.ts:59
    (Async: EventListener.handleEvent)
    loadRuntimes pyconfig.ts:58
    connectedCallback pyconfig.ts:42
    <anonymous> main.ts:29
    <anonymous> pyscript.js:27234
creating pyodide runtime pyodide.ts:41:16
Python initialization complete pyodide.asm.js:10:271183
loading micropip pyodide.ts:51:16
Loading micropip, pyparsing, packaging, distutils pyodide.asm.js:10:136383
Loaded micropip, packaging, pyparsing, distutils pyodide.asm.js:10:137532
loading pyscript... pyodide.ts:53:16
done setting up environment pyodide.ts:58:16
RUNTIME READY pyenv.ts:8:12
Collecting nodes to be mounted into python namespace... pyscript.ts:219:12
evaluate base.ts:100:16
console.trace() 
Object { src: "https://cdn.jsdelivr.net/pyodide/v0.21.2/full/pyodide.js", name: "pyodide-default", lang: "python", interpreter: {…}, globals: Proxy }
base.ts:106:20
    evaluate base.ts:106
    initialize runtime.ts:77
    loadRuntimes pyconfig.ts:59
    (Async: EventListener.handleEvent)
    loadRuntimes pyconfig.ts:58
    connectedCallback pyconfig.ts:42
    <anonymous> main.ts:29
    <anonymous> pyscript.js:27234
----> changed out to py-493bc6ca-5a1b-d659-6e60-a158dafd047c true 2 pyodide.asm.js:10:198133
Element.write: 09/03/2022, 22:08:34 --> True pyodide.asm.js:10:198133
----> reverted 3 pyodide.asm.js:10:198133
scripts queue set runtime.ts:19:12
------ loader closed ------ runtime.ts:84:20
Collecting nodes... pyscript.ts:183:12
===PyScript page fully initialized=== runtime.ts:89:16
registered handlers pybutton.ts:60:20
Source map error: Error: request failed with status 404
Resource URL: https://cdn.jsdelivr.net/pyodide/v0.21.2/full/pyodide.js
Source Map URL: pyodide.js.map

Initially I wrapped the customElements in a setTimeout and waited for 2.5s. This was sufficient most of the time, but there were some odd times that it wasn't. Increasing it to 3s made the button appear after the page loaded, which looked odd.

The main.js file will only create elements for PyScript, PyConfig, PyLoader and PyEnv. and the rest of the elements will be created once the runtime loads successfully and we closed the loader. With this change, the elements were always rendered successfully on the page and the error Cannot use 'in' operator to search for 'run' in undefined stopped.

Initially, the createCustomElements was in the utils.ts but that caused jest to fail with a strange behaviour, so this function was moved to its own file.

Removing the time.sleep from tests

While working on the tests last week (or two?) I added a few time.sleep because events weren't being triggered correctly. After looking into the py-button integration test and noticing that the clicks weren't registered, I started looking into the PyScriptTest and the PyScript code.

The PyScriptTest will wait for ===PyScript page fully initialized=== to be printed in the console, once playwright sees the log, it starts the tests and in this case, the clicking. But the script hasn't been added to the head of the page yet, so no event is registered. Here's the relevant code:

pyscript/pyscriptjs/src/components/pyconfig.ts

Line 68 in e31e03a

document.head.appendChild(script);

Adding a small page.wait_for_timeout was enough for the tests to start passing 😄 I'm wondering if perhaps we can make this timeout even smaller?

In a few tests, I've also added a self.page.wait_for_selector which seems to work nicely so playwright will wait until the element is loaded before trying to click or check the contents of the selector.

Please let me know if you would like me to change anything here (or if my assumptions/observations are incorrect 😄 )

Fixes: #673, #677, #726

[antocuni]

Wow, very good debugging/investigation in this PR, thank you!
I am a bit confused about this though:

The PyScriptTest will wait for ===PyScript page fully initialized=== to be printed in the console, once playwright sees the log, it starts the tests and in this case, the clicking. But the script hasn't been added to the head of the page yet, so no event is registered. Here's the relevant code:

I don't understand how this is possible.
(In the following I will put links to the source code in #737 because the logging is better and easier to follow, but the core logic is unchanged).
This is the workflow:

1. PyConfig.connectedCallback() is called, and it calls this.loadRuntimes()
   

   pyscript/pyscriptjs/src/components/pyconfig.ts

   Lines 46 to 50 in 4694602

   	appConfig.set(this.values);
   	logger.info('config set:', this.values);
   	this.loadRuntimes();
   	}

2. in loadRuntimes, we create the <script> tag to download pyodide, add a load event listener and append it to document.head:
   

   pyscript/pyscriptjs/src/components/pyconfig.ts

   Lines 62 to 73 in 4694602

   	loadRuntimes() {
   	logger.info('Initializing runtimes');
   	for (const runtime of this.values.runtimes) {
   	const runtimeObj: Runtime = new PyodideRuntime(runtime.src, runtime.name, runtime.lang);
   	const script = document.createElement('script'); // create a script DOM node
   	script.src = runtimeObj.src; // set its src to the provided URL
   	script.addEventListener('load', () => {
   	void runtimeObj.initialize();
   	});
   	document.head.appendChild(script);
   	}
   	}

3. Once the script has been loaded, the load event is fired and we call runtimeObj.initialize()

4. runtimeObj.initialize() is this, and at the end it prints PyScript page fully initialized:
   

   pyscript/pyscriptjs/src/runtime.ts

   Lines 135 to 181 in 4694602

   	async initialize(): Promise<void> {
   	loader?.log('Loading runtime...');
   	await this.loadInterpreter();
   	const newEnv = {
   	id: 'default',
   	runtime: this,
   	state: 'loading',
   	};
   	runtimeLoaded.set(this);
   	// Inject the loader into the runtime namespace
   	// eslint-disable-next-line
   	this.globals.set('pyscript_loader', loader);
   	loader?.log('Runtime created...');
   	loadedEnvironments.update(environments => ({
   	...environments,
   	[newEnv['id']]: newEnv,
   	}));
   	// now we call all initializers before we actually executed all page scripts
   	loader?.log('Initializing components...');
   	for (const initializer of initializers_) {
   	await initializer();
   	}
   	loader?.log('Initializing scripts...');
   	for (const script of scriptsQueue_) {
   	await script.evaluate();
   	}
   	scriptsQueue.set([]);
   	// now we call all post initializers AFTER we actually executed all page scripts
   	loader?.log('Running post initializers...');
   	if (appConfig_ && appConfig_.autoclose_loader) {
   	loader?.close();
   	}
   	for (const initializer of postInitializers_) {
   	await initializer();
   	}
   	// NOTE: this message is used by integration tests to know that
   	// pyscript initialization has complete. If you change it, you need to
   	// change it also in tests/integration/support.py
   	logger.info('PyScript page fully initialized');
   	}

So, I don't really understand how it is possible that (4) is called before the <script> is added to the head. I also tried to put a console.log after document.head.appendChild(script) and I confirm that it's printed way before PyScript page fully initialized.

So, there must be another reason for why the time.sleep is needed, but I think this investigation should not be a blocker to merge this PR, as it contains a lot of good stuff.

Moreover, I plan to do completely do a refactoring to improve the life cycle of a page and probably the code will change a lot, so maybe it's better to continue the investigation after the refactoring.

[FabioRosado]

Thank you for the review and the walkthrough! I was clearly wrong thinking that the appendChild step was the reason why we had to wait a short period of time 🤔

pyscript/pyscriptjs/src/components/pyconfig.ts

Line 71 in f3157b3

document.head.appendChild(script);

Although I should have added a log statement there, but I forgot 😞

So yeah, It's a mystery still why we need to wait this short time, I'll probably poke at it a bit more to see if I can figure out what's happening 😄

[antocuni]

also, I see that currently the tests are failing because of test_d3. This test seems to be flaky, I have already seen it failing occasionally 😞

[antocuni]

Thank you, looks good to me!
Another related issue is #763 which aims to refactor heavily the life cycle of a page, but I'm happy to merge this PR immediately.
Thank you!