Locking while writing to stdout may give a deadlock

[cwmos]

When stdout is flushed from a thread in a webworker, it seems like the thread will not continue until the data has been handled by the main thread. This may lead to a deadlock.

Here is a simple example where stdout is used for logging and protected by a lock. Protecting by a lock is necessary in order to avoid corruption of the output - see https://stackoverflow.com/questions/6374264/is-cout-synchronized-thread-safe.

#include <emscripten.h>
#include <thread>
#include <mutex>
#include <iostream>

std::mutex lock;

void myLogFunction(const char* txt) {
  lock.lock();
  std::cout << txt << "\n" << std::flush;
  lock.unlock();
}

extern "C" void EMSCRIPTEN_KEEPALIVE mainFunction() {
  myLogFunction("We are in the main thread");
}

void callFromWorker() {
  MAIN_THREAD_ASYNC_EM_ASM({
    Module._mainFunction();
  });

  myLogFunction("We are in the webworker");
}

int main() {
  new std::thread(callFromWorker);
}

This code deadlocks.

(The code it even hangs chrome in the sense that it is impossible to close the browser tab running the code or the browser itself But I guess this should be fixed in Chrome and likely they are aware of this problem.)

I understand that making stdout asynchronous may give other problems in terms of the webworker producing the output faster than the main thread can consume it leading to memory issues. Still, this may be a better solution than the current one.

[juj]

Yes, this is unfortunately currently expected to deadlock. :/ The bad pattern here is essentially

#include <emscripten.h>
#include <thread>
#include <mutex>
std::mutex lock;
extern "C" void EMSCRIPTEN_KEEPALIVE foo() {
  lock.lock();
  MAIN_THREAD_EM_ASM({}); // Synchronously block to wait for the main thread
  lock.unlock();
}
void worker() {
  MAIN_THREAD_ASYNC_EM_ASM({Module._foo()}); // Make main thread want to call foo()
  foo();
}
int main() {
  new std::thread(worker);
}

Not even -s PROXY_TO_PTHREAD=1 will help here.

The issue here is that fd_write is a synchronous syscall. It needs to be synchronous for two reasons: calling fd_write passes a pointer of data to the function, and there is a return value to observe back from the call.

So what happens is the pthread initiates a sync syscall while holding the lock, so it is waiting for main thread to finish fd_write for it, and main thread attempts to get lock.lock() to satisfy the MAIN_THREAD_ASYNC_EM_ASM block. Note that proxied requests are queued in-order, so the main thread does not even get to process the fd_write call, but the proxied call queue for the main thread has the two entries, the MAIN_THREAD_ASYNC_EM_ASM request, and the fd_write request, and it is stuck processing the first.

The first part could be fixed, there is already a machinery in place for satellite buffers, e.g. WebGL call proxying utilizes this. So the data to be printed could be copied off to a separate satellite data section that travels with the proxied message, and main thread would then free the satellite data.

The second part however about the return value (number of bytes written) cannot be fixed without breaking away from WASI syscall layer.

ASMFS shows one design to fix this problem, as it buffers fully multithreaded without proxying, and only full lines get printed via console.log/console.error in the worker that invokes the call. So printing does not have either sync or async proxying in ASMFS. (Although ASMFS is not yet multithreading safe in general, and unfortunately currently on a hiatus, it regressed when wasi syscalls were implemented, and I have not had time to fix it back)

[cwmos]

Thank you for the detailed explanation. I understand there is no obvious way to fix with this. For my use case I ended up just calling console.log directly using EM_ASM in the webworker without sending the log to stdout to the main thread. Perhaps emscripten can solve it in a similar way by letting it be up to the user of emscripten to deal with the stdout data in the webworker. I understand that it may be difficult to find a good place for the user of emscripten to provide this function.

[stale]

This issue has been automatically marked as stale because there has been no activity in the past year. It will be closed automatically if no further activity occurs in the next 30 days. Feel free to re-open at any time if this issue is still relevant.