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

wp-now: environment crashes when I try to save post #416

Closed
wojtekn opened this issue May 23, 2023 · 25 comments
Closed

wp-now: environment crashes when I try to save post #416

wojtekn opened this issue May 23, 2023 · 25 comments
Labels
[Feature] PHP.wasm [Type] Bug An existing feature does not function as intended

Comments

@wojtekn
Copy link
Collaborator

wojtekn commented May 23, 2023

I tried using wp-now for a blog, but it kept crashing when I saved the post. It preserved changes in the post being saved, though.

The output looked as follows:

$ wp-now start --php=7.4
Starting the server......
directory: /Volumes/Sites/blog
mode: wordpress
php: 7.4
wp: latest
WordPress latest folder already exists. Skipping download.
SQLite folder already exists. Skipping download.
Server running at http://127.0.0.1:8881/
zend_mm_heap corrupted
zsh: bus error  wp-now start --php=7.4

The site has the following plugins installed:

  • Akismet Anti-Spam 5.0.2
  • Crayon Syntax Highlighter 2.8.4
  • Google Authenticator 0.54
  • Jetpack 11.7.1
  • WP-PostViews 1.76.1

I tried to identify which plugin may cause it. I disabled all and was able to save posts without a crash. Then I started enabling them one by one to see when it starts crashing. It hasn't started crashing again, but I couldn't enable Jetpack as it displays "An error occurred. Please try again." when I click "Set up Jetpack", so I think it may be connected to Jetpack.

@danielbachhuber
Copy link
Member

Maybe it's Jetpack making outbound HTTP requests? Potentially related #396

@wojtekn
Copy link
Collaborator Author

wojtekn commented May 23, 2023

@danielbachhuber, it may be, but I'm not sure how to debug it more.

I've just imported the database dump to have the Jetpack connection active, started wp-now, accepted the Jetpack safe mode, saved the post, and it crashes again.

@adamziel
Copy link
Collaborator

adamziel commented May 23, 2023

A stack trace would be so super helpful here. Building with Assertions, no optimizations, and MM error reporting could yield a stack trace.

If not, then here's the next best thing:

  • Set a JavaScript breakpoint in VS Code
  • Step through the execution, keep track of the current stack trace
  • Go until wasm crashes
  • Post the last noted stack trace here

With the stack trace, we could poke around and figure out what to do next.

@wojtekn wojtekn self-assigned this May 24, 2023
@wojtekn
Copy link
Collaborator Author

wojtekn commented May 24, 2023

@adamziel thanks for providing more details. I've made those changes in Dockerfile, recompiled PHP and ran build:

npm run recompile:php:web
npm run build

Then, I started the server using wp-now start --php=7.4 and triggered it to crash:

Starting the server......
directory: /Volumes/Sites/blog
mode: wordpress
php: 7.4
wp: latest
WordPress latest folder already exists. Skipping download.
SQLite folder already exists. Skipping download.
Server running at http://127.0.0.1:8881/
zend_mm_heap corrupted
Trace: Error: Program terminated with exit(1)
    at _NodePHP.#handleRequest (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67743:24)
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async _NodePHP.run (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67518:12)
    at async PHPRequestHandler.#dispatchToPHP (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67130:14)
    at async PHPRequestHandler.request (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67038:12)
    at async PHPBrowser.request (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:66832:22)
    at async file:///Volumes/Sites/wordpress-playground/dist/packages/wp-now/main.js:744:20 {
  cause: ExitStatus {
    name: 'ExitStatus',
    message: 'Program terminated with exit(1)',
    status: 1
  }
}
    at file:///Volumes/Sites/wordpress-playground/dist/packages/wp-now/main.js:751:15
    at processTicksAndRejections (node:internal/process/task_queues:95:5)

I've checked paths from the stack trace but can't see anything obvious.

@adamziel
Copy link
Collaborator

index.cjs:67743 rethrows the error with the original one as a cause:

      const rethrown = new Error(message);
      rethrown.cause = err;
      throw rethrown;

The console message doesn't seem to give us the original one with WASM details in it. What would it say if you added an explicit console.error(err) before it rethrows?

@wojtekn
Copy link
Collaborator Author

wojtekn commented May 24, 2023

@adamziel it looks like it's this one, so it was included as cause:

ExitStatus {
    name: 'ExitStatus',
    message: 'Program terminated with exit(1)',
    status: 1
  }

@adamziel
Copy link
Collaborator

Oh, I see! So it has no .trace?

@wojtekn
Copy link
Collaborator Author

wojtekn commented May 25, 2023

@adamziel no, just the ExitStatus object I included in previous comments.

I searched more for the zend_mm_heap corrupted error and found other reports saying that when this memory leak occurs, PHP crashes and doesn't provide any debug trace.

I thought it might be caused by output_buffering, which is set to 0 for wp-now, but changing it to the default value didn't help.

I also noticed that I don't need to save the post to crash it. It crashes as soon as I load the post edit form and refresh it. I can refresh any other page normally, and I reproduce the crash only on post and page forms.

@adamziel
Copy link
Collaborator

adamziel commented May 25, 2023

@wojtekn oh, it seems like Emscripten throws an instance of a custom ExitStatus class that is not a JavaScript Error and has no .trace attached:

quit_(code, new ExitStatus(code));

https://github.com/WordPress/wordpress-playground/blob/043f677f36528e72108d8d6fa8b4d311ec43bf2d/packages/php-wasm/node/public/php_7_4.js#LL474C10-L474C10

We should patch it to expose a stack trace. Perhaps overriding quit_ in the Emscripten module would do the trick?

Either way, try manually replacing function ExitStatus for class ExitStatus extends Error { constructor() {. This should tell us where in the Wasm does it crash. If nothing changes, you may need to run nx reset, too.

found other reports saying that when this memory leak occurs, PHP crashes and doesn't provide any debug trace.

PHP may not provide any, but we’re running it as WebAssembly in JavaScript program and have extra powers. Emscripten JS module controls the entire execution flow. We could e.g. make it log every PHP function called. We should be able to get the trace when it crashes. The fact that we’re not getting one now seems like a bug, not a limitation.

@wojtekn
Copy link
Collaborator Author

wojtekn commented May 25, 2023

@adamziel I've replaced that ExitStatus class with the following:

  class ExitStatus extends Error {
	  constructor(status) {
		  super(status);
		  this.name = "ExitStatus";
		  this.message = "Program terminated with exit(" + status + ")";
		  this.status = status;
	  }
  }

And logged exception using console.log(e); in the catch section in BasePHP.#handleRequest:

Trace: Error: Program terminated with exit(1)
    at _NodePHP.#handleRequest (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67748:24)
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async _NodePHP.run (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67521:12)
    at async PHPRequestHandler.#dispatchToPHP (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67133:14)
    at async PHPRequestHandler.request (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67041:12)
    at async PHPBrowser.request (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:66835:22)
    at async file:///Volumes/Sites/wordpress-playground/dist/packages/wp-now/main.js:744:20 {
  cause: Error: Rethrown
      at UnhandledRejectionsTarget.errorListener (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:67713:28)
      at UnhandledRejectionsTarget.[nodejs.internal.kHybridDispatch] (node:internal/event_target:735:20)
      at UnhandledRejectionsTarget.dispatchEvent (node:internal/event_target:677:26)
      at runtime.asm.<computed> (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:66639:18)
      at invoke_vii (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:31621:7)
      at php_call_shutdown_functions (wasm://wasm/02a05cc6:wasm-function[10198]:0x59d503)
      at byn$fpcast-emu$php_call_shutdown_functions (wasm://wasm/02a05cc6:wasm-function[16201]:0x661330)
      at call (wasm://wasm/02a05cc6:wasm-function[5664]:0x400378)
      at ret.<computed> (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:30922:33)
      at runtime.asm.<computed> (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:66620:18)
      at invoke_v (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:31654:7)
      at php_request_shutdown (wasm://wasm/02a05cc6:wasm-function[2352]:0x1a04b2)
      at wasm_sapi_request_shutdown (wasm://wasm/02a05cc6:wasm-function[8847]:0x52396a)
      at byn$fpcast-emu$wasm_sapi_request_shutdown (wasm://wasm/02a05cc6:wasm-function[14662]:0x65a877)
      at call (wasm://wasm/02a05cc6:wasm-function[5664]:0x400378)
      at ret.<computed> (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:30922:33) {
    cause: ExitStatus: Program terminated with exit(1)
        at _proc_exit (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:29715:17)
        at exitJS (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:29722:5)
        at zend_mm_panic (wasm://wasm/02a05cc6:wasm-function[1027]:0x9cd0b)
        at _efree_48 (wasm://wasm/02a05cc6:wasm-function[524]:0x3ec62)
        at zend_array_destroy (wasm://wasm/02a05cc6:wasm-function[387]:0x2ea5e)
        at mysqlnd_mysqlnd_res_fetch_into_pub (wasm://wasm/02a05cc6:wasm-function[10537]:0x5c967b)
        at byn$fpcast-emu$mysqlnd_mysqlnd_res_fetch_into_pub (wasm://wasm/02a05cc6:wasm-function[16570]:0x66371f)
        at php_mysqli_fetch_into_hash (wasm://wasm/02a05cc6:wasm-function[2859]:0x1f3979)
        at zif_mysqli_fetch_object (wasm://wasm/02a05cc6:wasm-function[7673]:0x4bd4e9)
        at byn$fpcast-emu$zif_mysqli_fetch_object (wasm://wasm/02a05cc6:wasm-function[13426]:0x6549a0)
        at ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_USED_HANDLER (wasm://wasm/02a05cc6:wasm-function[20399]:0x6af833)
        at byn$fpcast-emu$ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_USED_HANDLER (wasm://wasm/02a05cc6:wasm-function[19034]:0x66db19)
        at execute_ex (wasm://wasm/02a05cc6:wasm-function[11412]:0x627122)
        at byn$fpcast-emu$execute_ex (wasm://wasm/02a05cc6:wasm-function[17478]:0x668090)
        at zend_call_function (wasm://wasm/02a05cc6:wasm-function[355]:0x2bd96)
        at _call_user_function_ex (wasm://wasm/02a05cc6:wasm-function[349]:0x2a5ec) {
      status: 1,
      cause: Error
          at Object.Asyncify.handleSleep (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:31849:45)
          at _wasm_poll_socket (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:30776:21)
          at php_pollfd_for (wasm://wasm/02a05cc6:wasm-function[930]:0x93062)
          at php_sockop_read (wasm://wasm/02a05cc6:wasm-function[9945]:0x57c0fa)
          at byn$fpcast-emu$php_sockop_read (wasm://wasm/02a05cc6:wasm-function[15916]:0x65f652)
          at php_openssl_sockop_io (wasm://wasm/02a05cc6:wasm-function[5104]:0x39859f)
          at php_openssl_sockop_read (wasm://wasm/02a05cc6:wasm-function[9995]:0x582789)
          at byn$fpcast-emu$php_openssl_sockop_read (wasm://wasm/02a05cc6:wasm-function[15977]:0x65fcbe)
          at _php_stream_fill_read_buffer (wasm://wasm/02a05cc6:wasm-function[3034]:0x20d020)
          at _php_stream_read (wasm://wasm/02a05cc6:wasm-function[205]:0x16c58)
          at mysqlnd_mysqlnd_vio_network_read_pub (wasm://wasm/02a05cc6:wasm-function[10451]:0x5bf404)
          at byn$fpcast-emu$mysqlnd_mysqlnd_vio_network_read_pub (wasm://wasm/02a05cc6:wasm-function[16485]:0x662d81)
          at mysqlnd_mysqlnd_pfc_receive_pub (wasm://wasm/02a05cc6:wasm-function[10567]:0x5cc42f)
          at byn$fpcast-emu$mysqlnd_mysqlnd_pfc_receive_pub (wasm://wasm/02a05cc6:wasm-function[16600]:0x663de6)
          at mysqlnd_read_header (wasm://wasm/02a05cc6:wasm-function[3696]:0x28f32a)
          at mysqlnd_read_packet_header_and_body (wasm://wasm/02a05cc6:wasm-function[1240]:0xb6473)
    },
    betterMessage: 'Program terminated with exit(1)'
  }
}
    at file:///Volumes/Sites/wordpress-playground/dist/packages/wp-now/main.js:751:15
    at processTicksAndRejections (node:internal/process/task_queues:95:5)

@wojtekn
Copy link
Collaborator Author

wojtekn commented May 25, 2023

@adamziel I've checked emscripten repository for that, and it looks like this change was made deliberately to fix some memory leak issue in Chrome:

emscripten-core/emscripten#9108

@adamziel
Copy link
Collaborator

adamziel commented May 25, 2023

I've checked emscripten repository for that, and it looks like this change was made deliberately to fix some memory leak issue in Chrome:

@wojtekn excellent find! We may ignore that tbh – Emscripten, the framework, made the right call here, but for us the entire runtime is about PHP. If the PHP dies, we may kill the entire process and reclaim any memory that leaked in the process of shutting down the WebAssembly module. Exposing the stack trace by default will make debugging all such issues much easier. Probably even the pthreads one.

I filed a separate issue here: #450

@adamziel
Copy link
Collaborator

adamziel commented May 25, 2023

The stack trace is extremely helpful, thank you for taking the time to provide it @wojtekn! The call to zend_array_destroy after mysqlnd_mysqlnd_res_fetch_into_pub tries to work on a memory region that holds something unexpected.

The _efree_48 call makes me think it could be a malloc vs emalloc issue in php_wasm.c, but I'm not sure why it would do efree any resource allocated by us. It could also be an entirely different problem. I wonder what is the array that it is trying to free, what's in there, and what is the problem with freeing it.

adamziel added a commit that referenced this issue May 30, 2023
…race attached (#470)

## Description

Overrides Emscripten's default ExitStatus object which gets thrown on
failure. Unfortunately, the default object is not a subclass of Error
and does not provide any stack trace.

This is a deliberate behavior on Emscripten's end to prevent memory
leaks after the program exits. See:

emscripten-core/emscripten#9108

In case of WordPress Playground, the worker in which the PHP runs will
typically exit after the PHP program finishes, so we don't have to worry
about memory leaks.

As for assigning to a previously undeclared ExitStatus variable here,
the Emscripten module declares `ExitStatus` as `function ExitStatus`
which means it gets hoisted to the top of the scope and can be
reassigned here – before the actual declaration is reached.

If that sounds weird, try this example:

```js
ExitStatus = () => { console.log("reassigned"); }
function ExitStatus() {}
ExitStatus();
// logs "reassigned"
```

## Testing instructions

Confirm the CI tests passed

Related: #416
cc @wojtekn
@wojtekn
Copy link
Collaborator Author

wojtekn commented May 30, 2023

@adamziel I found an open PHP bug https://bugs.php.net/bug.php?id=79781 which ends up with a slightly similar result. I ran the test script using wp-now and reproduced it.

The stack trace looked as follows:

ExitStatus: Program terminated with exit(1)
    at _proc_exit (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:22668:17)
    at exitJS (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:22675:5)
    at zend_mm_panic (wasm://wasm/026ce4f6:wasm-function[1038]:0x94832)
    at _efree (wasm://wasm/026ce4f6:wasm-function[103]:0x7ca4)
    at zend_array_destroy (wasm://wasm/026ce4f6:wasm-function[381]:0x28b40)

And one for my blog is:

ExitStatus: Program terminated with exit(1)
        at _proc_exit (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:29744:17)
        at exitJS (/Volumes/Sites/wordpress-playground/dist/packages/php-wasm/node/index.cjs:29751:5)
        at zend_mm_panic (wasm://wasm/02a0664e:wasm-function[1027]:0x9cd0b)
        at _efree_48 (wasm://wasm/02a0664e:wasm-function[524]:0x3ec62)
        at zend_array_destroy (wasm://wasm/02a0664e:wasm-function[387]:0x2ea5e)

@adamziel
Copy link
Collaborator

adamziel commented May 30, 2023

@wojtekn Great find! I'm seeing a similar result, but including a memory exhausted error from PHP:

Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 4096 bytes) in test.php on line 4

  WASM ERROR
  Program terminated with exit(1)

/Users/cloudnik/www/Automattic/core/plugins/playground/dist/packages/php-wasm/node/index.cjs:29720
    quit_(code, new ExitStatus(code));
                ^
ExitStatus: Program terminated with exit(1)
    at _proc_exit (dist/packages/php-wasm/node/index.cjs:29720:17)
    at exitJS (dist/packages/php-wasm/node/index.cjs:29727:5)
    at zend_mm_panic (wasm://wasm/02a0664e:wasm-function[1027]:0x9cd0b)
    at _efree (wasm://wasm/02a0664e:wasm-function[102]:0xa53a)

We set USE_ZEND_ALLOC=0 in php_wasm.c and the PHP issue mentions that briefly. I wonder if that's related? Does anything change if you set it to USE_ZEND_ALLOC=1?

@adamziel adamziel added [Type] Bug An existing feature does not function as intended and removed Local Environment labels Jun 1, 2023
@wojtekn
Copy link
Collaborator Author

wojtekn commented Aug 11, 2023

I'm leaving this issue at this time as I don't have enough bandwidth.

@wojtekn wojtekn removed their assignment Aug 11, 2023
@dmsnell
Copy link
Member

dmsnell commented Aug 11, 2023

Thanks @wojtekn for your dedication here; totally understandable. I struggle myself with getting the bandwidth to follow-up on stuff like this issue. We'll get to it at some point.

Pookie717 added a commit to Pookie717/wordpress-playground that referenced this issue Oct 1, 2023
…race attached (#470)

## Description

Overrides Emscripten's default ExitStatus object which gets thrown on
failure. Unfortunately, the default object is not a subclass of Error
and does not provide any stack trace.

This is a deliberate behavior on Emscripten's end to prevent memory
leaks after the program exits. See:

emscripten-core/emscripten#9108

In case of WordPress Playground, the worker in which the PHP runs will
typically exit after the PHP program finishes, so we don't have to worry
about memory leaks.

As for assigning to a previously undeclared ExitStatus variable here,
the Emscripten module declares `ExitStatus` as `function ExitStatus`
which means it gets hoisted to the top of the scope and can be
reassigned here – before the actual declaration is reached.

If that sounds weird, try this example:

```js
ExitStatus = () => { console.log("reassigned"); }
function ExitStatus() {}
ExitStatus();
// logs "reassigned"
```

## Testing instructions

Confirm the CI tests passed

Related: WordPress/wordpress-playground#416
cc @wojtekn
@wojtekn
Copy link
Collaborator Author

wojtekn commented Oct 17, 2023

I tested WordPress/playground-tools#110 along with #639, and unfortunately it still crashes.

@seanmorris
Copy link
Contributor

seanmorris commented Dec 15, 2023

I tested WordPress/playground-tools#110 along with #639, and unfortunately it still crashes.

Can you try this one: #870 ? It looks like these are actually two separate issues.

@wojtekn
Copy link
Collaborator Author

wojtekn commented Jan 8, 2024

I couldn't reproduce my site crashing with the #870 anymore. However, now it doesn't crash on the latest playground-tools trunk, too.

@adamziel
Copy link
Collaborator

adamziel commented Jan 9, 2024

@wojtekn oh, interesting! So did WordPress/playground-tools@29dba5d fix it? As in, does it crash one commit before that? I wonder if some change in the Playground repo helped here, or was it perhaps a new Node.js release.

@adamziel
Copy link
Collaborator

adamziel commented Jan 9, 2024

Actually no, that shouldn't fix it because it did not change any Playground dependencies. So weird!

@adamziel
Copy link
Collaborator

adamziel commented Feb 2, 2024

I fixed the stack overflow error related to the POST request:

#993

I still don't have any updates about the the crash related to simply loading the website.

@adamziel adamziel modified the milestone: PHP Feature Parity Feb 29, 2024
@adamziel adamziel modified the milestones: PHP Feature Parity, Zero Crashes Feb 29, 2024
@wojtekn
Copy link
Collaborator Author

wojtekn commented Mar 12, 2024

@adamziel as I no longer reproduce it, should we close?

@adamziel
Copy link
Collaborator

adamziel commented Mar 12, 2024

@wojtekn Yeah, let's close and reopen if this problem ever returns. I went through the logs in this issue once again just to be sure and some of them are familiar and seem related to some WASM issues we've solved lately.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
[Feature] PHP.wasm [Type] Bug An existing feature does not function as intended
Projects
Archived in project
Status: No status
Development

No branches or pull requests

5 participants