Help investigating asyncify failure

68 views
Skip to first unread message

Beuc

unread,
Sep 4, 2019, 5:10:39 PM9/4/19
to emscripte...@googlegroups.com
Hi,

Trying to test my Emscripten project with Asyncify, I recompiled it with tot-upstream, with the same whitelist, but this is failing:

Part 1) Handling function names that change (work-around)

I read that using function prefixes worked as limited wildcard but that doesn't seem to be the case - did I do something wrong?
-s ASYNCIFY_WHITELIST='["__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_"...'
warning: Asyncify whitelist contained a non-existing function name: __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_ ($__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_)

Also llvm-nm doesn't seem to support listing WASM.
I managed to find the function through emcc ... -o fat.llvm && llvm-nm fat.llvm :
003832c5 t __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_28draw_screen

Part 2) Run-time failure

With the updated WHITELIST, I got the dreaded:

RuntimeError: unreachable executed index.wasm:386701:1

__pyx_pw_11pygame_sdl2_7display_21flip http://localhost:8000/index.wasm:386701
emu$__pyx_pw_11pygame_sdl2_7display_21flip http://localhost:8000/index.wasm:8749855
15 http://localhost:8000/index.wasm:2587748
__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_28draw_screen http://localhost:8000/index.wasm:2845914
__pyx_pw_5renpy_2gl_6gldraw_6GLDraw_29draw_screen http://localhost:8000/index.wasm:2813529
emu$__pyx_pw_5renpy_2gl_6gldraw_6GLDraw_29draw_screen http://localhost:8000/index.wasm:8760622
PyCFunction_Call http://localhost:8000/index.wasm:5272869
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5750951
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
function_call http://localhost:8000/index.wasm:5167287
emu$function_call http://localhost:8000/index.wasm:8793327
PyObject_Call http://localhost:8000/index.wasm:5030529
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5754056
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
function_call http://localhost:8000/index.wasm:5167287
emu$function_call http://localhost:8000/index.wasm:8793327
PyObject_Call http://localhost:8000/index.wasm:5030529
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5754056
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5734704
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5734704
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
fast_function http://localhost:8000/index.wasm:5767904
PyEval_EvalFrameEx http://localhost:8000/index.wasm:5751409
PyEval_EvalCodeEx http://localhost:8000/index.wasm:5714071
PyEval_EvalCode http://localhost:8000/index.wasm:5710418
PyRun_FileExFlags http://localhost:8000/index.wasm:5955369
PyRun_SimpleFileExFlags http://localhost:8000/index.wasm:5954716
pyapp_runmain http://localhost:8000/index.wasm:58353
x http://localhost:8000/index.js:17649
handleSleep http://localhost:8000/index.js:17712
safeSetTimeout http://localhost:8000/index.js:9068

My whitelist:
-s ASYNCIFY_WHITELIST='["main", "pyapp_runmain", "SDL_WaitEvent", "SDL_WaitEventTimeout", "SDL_Delay", "SDL_RenderPresent", "GLES2_RenderPresent", "SDL_GL_SwapWindow", "Emscripten_GLES_SwapWindow", "PyRun_SimpleFileExFlags", "PyRun_FileExFlags", "PyEval_EvalCode", "PyEval_EvalCodeEx", "PyEval_EvalFrameEx", "PyCFunction_Call", "PyObject_Call", "fast_function", "function_call", "instancemethod_call", "slot_tp_call", "__pyx_pw_11pygame_sdl2_5event_7wait", "__pyx_pw_11pygame_sdl2_7display_21flip", "__pyx_pw_11pygame_sdl2_7display_6Window_13flip", "__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_28draw_screen", "__pyx_pw_5renpy_2gl_6gldraw_6GLDraw_29draw_screen", "__Pyx_PyObject_CallNoArg", "__pyx_pf_10emscripten_6sleep", "__pyx_pw_10emscripten_7sleep", "__pyx_pf_10emscripten_8sleep_with_yield", "__pyx_pw_10emscripten_9sleep_with_yield", "gen_send", "gen_send_ex", "gen_iternext", "type_call", "slot_tp_init", "builtin_eval"]'

Not sure if all the "emu$" and "fastfunction" are properly handled :/

Any clue?

Cheers!
Beuc

Alon Zakai

unread,
Sep 4, 2019, 7:22:31 PM9/4/19
to emscripte...@googlegroups.com
On Wed, Sep 4, 2019 at 2:10 PM Beuc <be...@beuc.net> wrote:
Hi,

Trying to test my Emscripten project with Asyncify, I recompiled it with tot-upstream, with the same whitelist, but this is failing:

Part 1) Handling function names that change (work-around)

I read that using function prefixes worked as limited wildcard but that doesn't seem to be the case - did I do something wrong?

Wildcards like "__py*" should work (with "*"). But the "*" can only be at the end currently, I believe.

  -s ASYNCIFY_WHITELIST='["__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_"...'
  warning: Asyncify whitelist contained a non-existing function name: __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_ ($__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_)

Also llvm-nm doesn't seem to support listing WASM.

Correct, llvm-nm is only aware of LLVM IR. Wasm object files contain wasm. To see the names in them, build with something like -g or --profiling (so names are kept) and use binaryen's wasm-dis. You can also inspect the binary directly.

I managed to find the function through emcc ... -o fat.llvm && llvm-nm fat.llvm :
  003832c5 t __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_28draw_screen


LLVM IR may encode the name differently than in wasm, as LLVM IR will use standard name mangling while wasm names will be "human-readable" (contain things like parentheses, types, ::, etc. - the output of c++filt).
 
Part 2) Run-time failure

With the updated WHITELIST, I got the dreaded:

RuntimeError: unreachable executed index.wasm:386701:1

An unreachable can be several things. If it in the binaryen API, it could be the asyncify stack is too small. But here it looks like it's in a user function - it could be that an import was called that started a sleep, but asyncify was not aware of it, and control flow ends up in the wrong place. Adding some debug logging in your sleep function, and making sure ASYNCIFY_IMPORTS is correct, might help.

Note that in ASSERTIONS mode we improved debug errors for that pretty recently, not sure if in the last version or since then.

--
You received this message because you are subscribed to the Google Groups "emscripten-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to emscripten-disc...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/emscripten-discuss/20190904211035.7a3v7rgwmiwser4n%40mail.beuc.net.

Beuc

unread,
Sep 4, 2019, 7:45:16 PM9/4/19
to emscripte...@googlegroups.com
Hi and thanks for the input,

A few quick points:

- the wildcard doesn't seem to work with '*' either:
warning: Asyncify whitelist contained a non-existing function name: __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_* ($__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_*)

- I was using tot-upstream, '-s ASSERTIONS=1 -g', and
'-s ASYNCIFY_STACK_SIZE=65535' (just in case)

- I'm using my patch from
https://github.com/emscripten-ports/SDL2/issues/70
hence emscripten_sleep()

Alon Zakai

unread,
Sep 4, 2019, 8:07:37 PM9/4/19
to emscripte...@googlegroups.com
On Wed, Sep 4, 2019 at 4:45 PM Beuc <be...@beuc.net> wrote:
Hi and thanks for the input,

A few quick points:

- the wildcard doesn't seem to work with '*' either:
  warning: Asyncify whitelist contained a non-existing function name: __pyx_pf_5renpy_2gl_6gldraw_6GLDraw_* ($__pyx_pf_5renpy_2gl_6gldraw_6GLDraw_*)


Ah, you're right, I was confused, sorry.

ASYNCIFY_IMPORTS supports such a wildcard, but the lists can't, since "*" is a valid character in human-readable function names... we'd need to add some kind of escaping support if we want it.

We do have ongoing work on adding a response file option to those, so that should make handling long lists easier.

- I was using tot-upstream, '-s ASSERTIONS=1 -g', and
  '-s ASYNCIFY_STACK_SIZE=65535' (just in case)

- I'm using my patch from
  https://github.com/emscripten-ports/SDL2/issues/70
  hence emscripten_sleep()


Hmm, no idea then. I'd suggest investigating this using -s WASM=0, that tends to be much easier to debug (can add console.logs, etc.). Sometimes just seeing the unreachable/abort in context helps understand what's going on.

--
You received this message because you are subscribed to the Google Groups "emscripten-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to emscripten-disc...@googlegroups.com.

Beuc

unread,
Sep 5, 2019, 9:28:04 AM9/5/19
to emscripte...@googlegroups.com

Hi,

I eventually tracked down a few missing functions using a simpler project.
If I understand correctly, those were tail calls.

The application feels a lot smoother, thanks :)

Note: I couldn't whitelist additional functions caused by EMULATE_FUNCTION_POINTER_CASTS, such as byn$fpcast_emu$__pyx_pw_11pygame_sdl2_7display_6Window_13flip (present in the .wasm but not recognized as part of the whitelist). Is this expected?

Cheers!
Beuc

Alon Zakai

unread,
Sep 6, 2019, 5:16:03 PM9/6/19
to emscripte...@googlegroups.com
Thanks! I think that's a pass ordering issue, we must run asyncify after fpcast-emu in order to affect those functions. WIP patch here, let me know if you can test that,


--
You received this message because you are subscribed to the Google Groups "emscripten-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to emscripten-disc...@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages