Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Code runs in Wasmer (Cranelift JIT) but crashes in wasmtime with out of bounds memory access #2638

Closed
abbec opened this issue Feb 5, 2021 · 20 comments · Fixed by #2649
Closed
Assignees
Labels
bug Incorrect behavior in the current implementation that needs fixing

Comments

@abbec
Copy link

abbec commented Feb 5, 2021

  • What are the steps to reproduce the issue?
    Run wasmtime run python.wasm --dir . -- -m test in a clone of cpython version 3.8 (or at least the Lib folder).
    python.wasm.zip

  • What do you expect to happen? What does actually happen? Does it panic, and
    if so, with which assertion?
    I expect it to run without crashing like Wasmer using the Cranelift JIT backend does.

Callstack
$ wasmtime run python.wasm --dir . -- -m test
Error: failed to run main module `python.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: out of bounds memory access
       wasm backtrace:
           0: 0x68557c - <unknown>!dlmalloc
           1: 0x68760e - <unknown>!realloc
           2: 0x452d56 - <unknown>!_PyMem_RawRealloc
           3: 0x457580 - <unknown>!_PyMem_DebugRawRealloc
           4: 0x4556ae - <unknown>!PyMem_RawRealloc
           5: 0x453028 - <unknown>!_PyObject_Realloc
           6: 0x457580 - <unknown>!_PyMem_DebugRawRealloc
           7: 0x4582ba - <unknown>!_PyMem_DebugRealloc
           8: 0x458587 - <unknown>!PyMem_Realloc
           9: 0x42c1b5 - <unknown>!list_resize
          10: 0x42c52f - <unknown>!app1
          11: 0x42c369 - <unknown>!PyList_Append
          12: 0x4af5b1 - <unknown>!_posix_listdir
          13: 0x49cad9 - <unknown>!os_listdir_impl
          14: 0x49c9a1 - <unknown>!os_listdir
          15: 0x20f6a5 - <unknown>!cfunction_vectorcall_FASTCALL_KEYWORDS
          16: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          17: 0x20a7d7 - <unknown>!call_function
          18: 0x1ffd1d - <unknown>!_PyEval_EvalFrameDefault
          19: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          20: 0x2d3d85 - <unknown>!function_code_fastcall
          21: 0x2d4508 - <unknown>!_PyFunction_Vectorcall
          22: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          23: 0x20a7d7 - <unknown>!call_function
          24: 0x1ffe37 - <unknown>!_PyEval_EvalFrameDefault
          25: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          26: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          27: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          28: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          29: 0x20a7d7 - <unknown>!call_function
          30: 0x1ffe37 - <unknown>!_PyEval_EvalFrameDefault
          31: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          32: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          33: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          34: 0x19e67e - <unknown>!_PyObject_Vectorcall
          35: 0x19dd65 - <unknown>!method_vectorcall
          36: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          37: 0x20a7d7 - <unknown>!call_function
          38: 0x1ffd1d - <unknown>!_PyEval_EvalFrameDefault
          39: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          40: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          41: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          42: 0x19e67e - <unknown>!_PyObject_Vectorcall
          43: 0x19dd65 - <unknown>!method_vectorcall
          44: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          45: 0x20a7d7 - <unknown>!call_function
          46: 0x200057 - <unknown>!_PyEval_EvalFrameDefault
          47: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          48: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          49: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          50: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          51: 0x20a7d7 - <unknown>!call_function
          52: 0x200057 - <unknown>!_PyEval_EvalFrameDefault
          53: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          54: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          55: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          56: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          57: 0x20a7d7 - <unknown>!call_function
          58: 0x1ffd1d - <unknown>!_PyEval_EvalFrameDefault
          59: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          60: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          61: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          62: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          63: 0x20a7d7 - <unknown>!call_function
          64: 0x200057 - <unknown>!_PyEval_EvalFrameDefault
          65: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          66: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          67: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          68: 0x20bc53 - <unknown>!_PyObject_Vectorcall
          69: 0x20a7d7 - <unknown>!call_function
          70: 0x200057 - <unknown>!_PyEval_EvalFrameDefault
          71: 0x1eac4f - <unknown>!PyEval_EvalFrameEx
          72: 0x1eaa0e - <unknown>!_PyEval_EvalCodeWithName
          73: 0x2d4a6c - <unknown>!_PyFunction_Vectorcall
          74: 0x2d2079 - <unknown>!PyVectorcall_Call
          75: 0x2d2407 - <unknown>!PyObject_Call
          76: 0x48a8dc - <unknown>!pymain_run_module
          77: 0x489a3e - <unknown>!pymain_run_python
          78: 0x489625 - <unknown>!Py_RunMain
          79: 0x48b4e9 - <unknown>!pymain_main
          80: 0x48b974 - <unknown>!Py_BytesMain
          81: 0x421d - <unknown>!main
          82: 0x68a7ff - <unknown>!__main_void
          83: 0x689d72 - <unknown>!__original_main
          84: 0x41b3 - <unknown>!_start
       note: run with `WASMTIME_BACKTRACE_DETAILS=1` environment variable to display more information
Detailed Callstack
$ WASMTIME_BACKTRACE_DETAILS=1 wasmtime run python.wasm --dir . -- -m test
Error: failed to run main module `python.wasm`

Caused by:
    0: failed to invoke command default
    1: wasm trap: out of bounds memory access
       wasm backtrace:
           0: 0x68557c - <unknown>!dlmalloc
           1: 0x68760e - <unknown>!realloc
           2: 0x452d56 - _PyMem_RawRealloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:122:12
           3: 0x457580 - _PyMem_DebugRawRealloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:2241:20
           4: 0x4556ae - PyMem_RawRealloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:591:12
           5: 0x453028 - _PyObject_Realloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:1987:12
           6: 0x457580 - _PyMem_DebugRawRealloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:2241:20
           7: 0x4582ba - _PyMem_DebugRealloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:2327:12
           8: 0x458587 - PyMem_Realloc
                           at /Users/abbe/code/gbk-python/Objects/obmalloc.c:624:12
           9: 0x42c1b5 - list_resize
                           at /Users/abbe/code/gbk-python/Objects/listobject.c:70:26
          10: 0x42c52f - app1
                           at /Users/abbe/code/gbk-python/Objects/listobject.c:340:9
          11: 0x42c369 - PyList_Append
                           at /Users/abbe/code/gbk-python/Objects/listobject.c:352:16
          12: 0x4af5b1 - _posix_listdir
                           at /Users/abbe/code/gbk-python/./Modules/posixmodule.c:3831:13
          13: 0x49cad9 - os_listdir_impl
                           at /Users/abbe/code/gbk-python/./Modules/posixmodule.c:3887:12
          14: 0x49c9a1 - os_listdir
                           at /Users/abbe/code/gbk-python/./Modules/clinic/posixmodule.c.h:1197:20
          15: 0x20f6a5 - cfunction_vectorcall_FASTCALL_KEYWORDS
                           at /Users/abbe/code/gbk-python/Objects/methodobject.c:437:24
          16: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          17: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          18: 0x1ffd1d - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3469:23
          19: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          20: 0x2d3d85 - function_code_fastcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:283:14
          21: 0x2d4508 - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:410:20
          22: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          23: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          24: 0x1ffe37 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3486:23
          25: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          26: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          27: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          28: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          29: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          30: 0x1ffe37 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3486:23
          31: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          32: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          33: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          34: 0x19e67e - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          35: 0x19dd65 - method_vectorcall
                           at /Users/abbe/code/gbk-python/Objects/classobject.c:60:18
          36: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          37: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          38: 0x1ffd1d - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3469:23
          39: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          40: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          41: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          42: 0x19e67e - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          43: 0x19dd65 - method_vectorcall
                           at /Users/abbe/code/gbk-python/Objects/classobject.c:60:18
          44: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          45: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          46: 0x200057 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3500:19
          47: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          48: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          49: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          50: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          51: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          52: 0x200057 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3500:19
          53: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          54: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          55: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          56: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          57: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          58: 0x1ffd1d - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3469:23
          59: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          60: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          61: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          62: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          63: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          64: 0x200057 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3500:19
          65: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          66: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          67: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          68: 0x20bc53 - _PyObject_Vectorcall
                           at /Users/abbe/code/gbk-python/./Include/cpython/abstract.h:127:11
          69: 0x20a7d7 - call_function
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4963:13
          70: 0x200057 - _PyEval_EvalFrameDefault
                           at /Users/abbe/code/gbk-python/Python/ceval.c:3500:19
          71: 0x1eac4f - PyEval_EvalFrameEx
                           at /Users/abbe/code/gbk-python/Python/ceval.c:741:12
          72: 0x1eaa0e - _PyEval_EvalCodeWithName
                           at /Users/abbe/code/gbk-python/Python/ceval.c:4298:14
          73: 0x2d4a6c - _PyFunction_Vectorcall
                           at /Users/abbe/code/gbk-python/Objects/call.c:435:12
          74: 0x2d2079 - PyVectorcall_Call
                           at /Users/abbe/code/gbk-python/Objects/call.c:199:24
          75: 0x2d2407 - PyObject_Call
                           at /Users/abbe/code/gbk-python/Objects/call.c:227:16
          76: 0x48a8dc - pymain_run_module
                           at /Users/abbe/code/gbk-python/Modules/main.c:302:14
          77: 0x489a3e - pymain_run_python
                           at /Users/abbe/code/gbk-python/Modules/main.c:600:21
          78: 0x489625 - Py_RunMain
                           at /Users/abbe/code/gbk-python/Modules/main.c:685:5
          79: 0x48b4e9 - pymain_main
                           at /Users/abbe/code/gbk-python/Modules/main.c:715:12
          80: 0x48b974 - Py_BytesMain
                           at /Users/abbe/code/gbk-python/Modules/main.c:739:12
          81: 0x421d - __main_argc_argv
                           at /Users/abbe/code/gbk-python/./Programs/python.c:16:12
          82: 0x68a7ff - <unknown>!__main_void
          83: 0x689d72 - <unknown>!__original_main
          84: 0x41b3 - _Py_hashtable_print_stats
                           at /Users/abbe/code/gbk-python/./Modules/hashtable.c:214

With Wasmer
$ wasmer run python.wasm --dir . -- -m test
Traceback (most recent call last):
  File "/Lib/threading.py", line 528, in set
    self._cond.notify_all()
  File "/Lib/threading.py", line 371, in notify_all
    self.notify(len(self._waiters))
  File "/Lib/threading.py", line 352, in notify
    raise RuntimeError("cannot notify on un-acquired lock")
RuntimeError: cannot notify on un-acquired lock

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Lib/runpy.py", line 194, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/Lib/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/Lib/test/__main__.py", line 1, in <module>
    from test.libregrtest import main
  File "/Lib/test/libregrtest/__init__.py", line 1, in <module>
    from test.libregrtest.cmdline import _parse_args, RESOURCE_NAMES, ALL_RESOURCES
  File "/Lib/test/libregrtest/cmdline.py", line 1, in <module>
    import argparse
  File "/Lib/argparse.py", line 89, in <module>
    import shutil as _shutil
  File "/Lib/shutil.py", line 22, in <module>
    import bz2
  File "/Lib/bz2.py", line 17, in <module>
    from threading import RLock
  File "/Lib/threading.py", line 1353, in <module>
    _main_thread = _MainThread()
  File "/Lib/threading.py", line 1265, in __init__
    self._started.set()
  File "/Lib/threading.py", line 528, in set
    self._cond.notify_all()
  File "/Lib/threading.py", line 250, in __exit__
    return self._lock.__exit__(*args)
RuntimeError: release unlocked lock
  • Which Wasmtime version / commit hash / branch are you using?
    0.22.1

  • If relevant, can you include some extra information about your environment?
    This is a custom port of Python to WASI and some things are not expected to work. However, running -m test with Wasmer gives the expected Python error whereas running it with Wasmtime gives a memory corruption.

Debugging further, the Python debug malloc (this is a debug build) gets an invalid allocation from dlmalloc causing it to overwrite some internal dlmalloc data structures.

Can also add that simpler things work fine in Wasmtime:

$ wasmtime run --dir . python.wasm
Python 3.8.6 (heads/embed-test-dirty:ee1910e462, Feb  5 2021, 12:02:19)
[Clang 11.0.0 ] on wasi
Type "help", "copyright", "credits" or "license" for more information.
>>> print("hello I am in wasmtime")
hello I am in wasmtime
>>> quit()

If there is a better way we can debug this to provide more/better info, please let us know!

@abbec abbec added the bug Incorrect behavior in the current implementation that needs fixing label Feb 5, 2021
@abbec abbec changed the title Code runs fine in Wasmer (Cranelift JIT) but crashes in wasmtime with out of bounds memory access Code runs in Wasmer (Cranelift JIT) but crashes in wasmtime with out of bounds memory access Feb 5, 2021
@pchickey
Copy link
Contributor

pchickey commented Feb 5, 2021

I was not able to reproduce this with 0.22.0 or main (e4827ad) on x64 linux. I assume from your homedir path that your crash is on x64 macos?

@alexcrichton
Copy link
Member

The backtrace also looks like it was in _posix_listdir in Python, so this may have been fixed by either #2620 or the large wasi rewrite in #2487. @abbec would you be able to test the master branch of wasmtime and see if it works for you?

@tschneidereit
Copy link
Member

Running the install script from wasmtime.dev again should install the latest build based on the main branch, so that should work for testing this, I think.

@tschneidereit
Copy link
Member

And indeed, with the latest build I don't get a crash. I do get an error about a missing import, though, which is what #2637 is about.

Output with the latest build
Could not find platform independent libraries <prefix>
Could not find platform dependent libraries <exec_prefix>
Consider setting $PYTHONHOME to <prefix>[:<exec_prefix>]
Python path configuration:
  PYTHONHOME = (not set)
  PYTHONPATH = (not set)
  program name = 'python.wasm'
  isolated = 0
  environment = 1
  user site = 1
  import site = 1
  sys._base_executable = ''
  sys.base_prefix = '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi'
  sys.base_exec_prefix = '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi'
  sys.executable = ''
  sys.prefix = '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi'
  sys.exec_prefix = '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi'
  sys.path = [
    '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi/lib/python38.zip',
    '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi/lib/python3.8',
    '/nix/store/7s2gi17s0hb2rjbdxn94cslllcabd13k-wasi-python38-wasm32-unknown-wasi-shell-wasm32-unknown-wasi/lib/lib-dynload',
  ]
Fatal Python error: init_fs_encoding: failed to get the Python codec of the filesystem encoding
Python runtime state: core initialized
ModuleNotFoundError: No module named 'encodings'

Current thread 0x00000001 (most recent call first):
<no Python frame>

@abbec
Copy link
Author

abbec commented Feb 5, 2021

@tschneidereit you need --dir pointing to a clone of cpython (or at least something containing a Lib folder)

@tschneidereit
Copy link
Member

Ah, I see. Does it work for you with that in the latest Wasmtime build?

@abbec
Copy link
Author

abbec commented Feb 5, 2021

I was not able to reproduce this with 0.22.0 or main (e4827ad) on x64 linux. I assume from your homedir path that your crash is on x64 macos?

Do you get the same as @tschneidereit because python needs a copy of its lib dir or else you will not "get to" the crash.

I did try latest but --dir seems broken there

@abbec
Copy link
Author

abbec commented Feb 5, 2021

The backtrace also looks like it was in _posix_listdir in Python, so this may have been fixed by either #2620 or the large wasi rewrite in #2487. @abbec would you be able to test the master branch of wasmtime and see if it works for you?

Ah that readdir fix does look interesting, will try that. Unfortunately the large wasi rewrite seems to have broken --dir (as stated in the comment above) so it isn't possible to test there :(

@alexcrichton
Copy link
Member

@abbec hm can you provide the exact invocations you're using of the wasmtime CLI? I'm only able to get the errors that @tschneidereit mentioned above regardless what version of wasmtime I use, I've never been able to get the original trap you mentioned.

@alexcrichton
Copy link
Member

Er, and to clarify, I don't know what repository of cpython you're using, what commit you're using, or the exact working directory of the invocation you gisted above.

@abbec
Copy link
Author

abbec commented Feb 5, 2021

Python needs access to its' standard library when running and I am using a checkout of cpython (the 3.8 branch) and passing that in as --dir .

The exact command line inside a cpython (branch 3.8) clone is wasmtime run python.wasm --dir . -- -m test

@abbec
Copy link
Author

abbec commented Feb 5, 2021

I can create a self-contained example

@abbec
Copy link
Author

abbec commented Feb 5, 2021

Here is a self-contained bundle with the crash. Just unpack and run run.sh inside the folder:
python-crash.zip

@pchickey
Copy link
Contributor

pchickey commented Feb 5, 2021

We made some subtle but, it turns out, breaking changes to how WASI rights work with the new wasi-common that landed yesterday. Without source code for how your python's wasi integration works, I can't debug much further, but here's what is going on to get you the [Errno 76] Capabilities insufficient: './Lib'. I produced this with the environment var RUST_LOG=wasi_common=trace on a debug build.

In short, it looks like when you opened the ./Lib directory under . (Fd(3)), the fs_rights_base argument did not contain the rights to do a readdir or any of the other typical directory operations - only the FILESTAT_GET | FILESTAT_SET_TIMES rights end up being applicable to directories from that set.

The entire WASI rights system is difficult to understand, poorly documented, implemented completely different (if at all) across various WASI implementations, and not actually very useful. We are going to get rid of it soon. In the meantime, I'm not sure why your code requested file rights as the base (this could very well be a bug in the wasi-common rewrite) and we should figure out how to debug that. I'm happy to look at your python WASI build source to help debug it, or hop on a zoom call together this afternoon...

 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > wiggle abi; module="wasi_snapshot_preview1" function="path_open"
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > fd=Fd(3) dirflags=Lookupflags(SYMLINK_FOLLOW (0x1)) path=*guest 0x0/3 oflags=Oflags(DIRECTORY (0x2)) fs_rights_base=Rights(FD_READ | FD_SEEK | FD_FDSTAT_SET_FLAGS | FD_SYNC | FD_TELL | FD_ADVISE | FD_FILESTAT_GET | FD_FILESTAT_SET_TIMES | POLL_FD_READWRITE (0x8a000be)) fs_rights_inheriting=Rights(FD_DATASYNC | FD_READ | FD_SEEK | FD_FDSTAT_SET_FLAGS | FD_SYNC | FD_TELL | FD_WRITE | FD_ADVISE | FD_ALLOCATE | FD_FILESTAT_GET | FD_FILESTAT_SET_SIZE | FD_FILESTAT_SET_TIMES | POLL_FD_READWRITE (0x8e001ff)) fdflags=Fdflags(NONBLOCK (0x4))
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > opened_fd=Fd(11)
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > success=No error occurred. System call completed successfully. (Errno::Success(0))
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > wiggle abi; module="wasi_snapshot_preview1" function="fd_readdir"
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > fd=Fd(11) buf=*guest 0xb83810 buf_len=4096 cookie=0
 DEBUG wasi_common::snapshots::preview_1                         > Error: desired READDIR, has FILESTAT_GET | FILESTAT_SET_TIMES

Caused by:
    Not capable
 TRACE wasi_common::snapshots::preview_1::wasi_snapshot_preview1 > error=Ok(Notcapable)

@abbec
Copy link
Author

abbec commented Feb 5, 2021

It is a largely unmodified Python except for a few "hacks".

A zoom call sounds super helpful and I am in the CEST time zone but suggest a time :)

Although that breakage is interesting though, this is more about the crash I get before that change :)

@pchickey
Copy link
Contributor

pchickey commented Feb 5, 2021

I backed up to v0.22.0 and the rights problem doesn't occur there. instead, we get all the way to a subtraction with overflow panic (compiling to debug mode helps here!) in our fd_readdir impl that has since been fixed (separately of the wasi-common rewrite #2620)

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > wiggle abi; module="wasi_snapshot_preview1" function="fd_readdir"
 TRACE wasi_common::wasi::wasi_snapshot_preview1      > fd=Fd(4) buf=*guest 0xc88970 buf_len=4096 cookie=1711012349524439084
 TRACE wasi_common::sys::unix::fd                     > fd_readdir: doing seekdir to 1711012349524439084
 TRACE wasi_common::wasi::wasi_snapshot_preview1      > bufused=4096
 TRACE wasi_common::wasi::wasi_snapshot_preview1      > success=No error occurred. System call completed successfully. (Errno::Success(0))
 TRACE wasi_common::wasi::wasi_snapshot_preview1      > wiggle abi; module="wasi_snapshot_preview1" function="fd_readdir"
 TRACE wasi_common::wasi::wasi_snapshot_preview1      > fd=Fd(4) buf=*guest 0xc88970 buf_len=4096 cookie=3052825016181861124
 TRACE wasi_common::sys::unix::fd                     > fd_readdir: doing seekdir to 3052825016181861124
thread 'main' panicked at 'attempt to subtract with overflow', crates/wasi-common/src/snapshots/wasi_snapshot_preview1.rs:310:51
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

@abbec
Copy link
Author

abbec commented Feb 5, 2021

Also, the code producing the binary is more or less here

@pchickey
Copy link
Contributor

pchickey commented Feb 5, 2021

ok. mailed you at the address in your github profile as well if you want to zoom in 30 mins

@abbec
Copy link
Author

abbec commented Feb 5, 2021

I backed up to v0.22.0 and the rights problem doesn't occur there. instead, we get all the way to a subtraction with overflow panic (compiling to debug mode helps here!) in our fd_readdir impl that has since been fixed (separately of the wasi-common rewrite #2620)


 TRACE wasi_common::wasi::wasi_snapshot_preview1      > wiggle abi; module="wasi_snapshot_preview1" function="fd_readdir"

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > fd=Fd(4) buf=*guest 0xc88970 buf_len=4096 cookie=1711012349524439084

 TRACE wasi_common::sys::unix::fd                     > fd_readdir: doing seekdir to 1711012349524439084

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > bufused=4096

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > success=No error occurred. System call completed successfully. (Errno::Success(0))

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > wiggle abi; module="wasi_snapshot_preview1" function="fd_readdir"

 TRACE wasi_common::wasi::wasi_snapshot_preview1      > fd=Fd(4) buf=*guest 0xc88970 buf_len=4096 cookie=3052825016181861124

 TRACE wasi_common::sys::unix::fd                     > fd_readdir: doing seekdir to 3052825016181861124

thread 'main' panicked at 'attempt to subtract with overflow', crates/wasi-common/src/snapshots/wasi_snapshot_preview1.rs:310:51

note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Wow! Nice find! Then we know that :) Thanks a lot!

@pchickey pchickey self-assigned this Feb 5, 2021
@abbec
Copy link
Author

abbec commented Feb 5, 2021

Just wanted to say that this was some serious first-class support! Thanks everyone! ❤️

pchickey added a commit that referenced this issue Feb 9, 2021
the fdstat of a dirfd needs to include both the file and dir rights in
the inheriting field.

The wasi-libc path_open bases the base rights of child directories off
the inheriting rights of the parent, so if we only put file rights in
there, opening a child directory will not have any directory operations
permitted.

Fixes #2638
sunfishcode pushed a commit that referenced this issue Feb 11, 2021
the fdstat of a dirfd needs to include both the file and dir rights in
the inheriting field.

The wasi-libc path_open bases the base rights of child directories off
the inheriting rights of the parent, so if we only put file rights in
there, opening a child directory will not have any directory operations
permitted.

Fixes #2638
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Incorrect behavior in the current implementation that needs fixing
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants