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.

Sign up for GitHub

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

Jump to bottom

Crash when using inside a worker #129

Closed
oanguenot opened this issue Aug 30, 2022 · 10 comments
Closed

Crash when using inside a worker #129

oanguenot opened this issue Aug 30, 2022 · 10 comments

Comments

@oanguenot
Copy link

Using Node LTS (v16.17.0), I tried to load and execute node-datachannel into a Node worker_threads.

It seems to start correctly, but I have the following error:
FATAL ERROR: HandleScope::HandleScope Entering the V8 API without proper locking in place

Here is the complete logs captured from the worker
2022-08-30 16:54:08.968 DEBUG [1837469] [rtc::impl::Init::doInit@120] Global initialization
2022-08-30 16:54:09.103 DEBUG [1837472] [rtc::impl::Certificate::Generate@223] Generating certificate (OpenSSL)
2022-08-30 16:54:09.103 VERB [1837469] [rtc::impl::PeerConnection::PeerConnection@59] Creating PeerConnection
2022-08-30 16:54:09.104 VERB [1837469] [rtc::impl::PeerConnection::PeerConnection@59] Creating PeerConnection
2022-08-30 16:54:09.104 DEBUG [1837471] [rtc::impl::Certificate::Generate@223] Generating certificate (OpenSSL)
2022-08-30 16:54:09.110 VERB [1837469] [rtc::PeerConnection::setLocalDescription@87] Setting local description, type=unspec
2022-08-30 16:54:09.110 VERB [1837469] [rtc::impl::PeerConnection::initIceTransport@146] Starting ICE transport
2022-08-30 16:54:09.110 DEBUG [1837469] [rtc::impl::IceTransport::IceTransport@58] Initializing ICE transport (libjuice)
2022-08-30 16:54:09.110 VERB [1837472] [rtc::impl::Certificate::Generate@239] Generating ECDSA P-256 key pair
2022-08-30 16:54:09.110 VERB [1837471] [rtc::impl::Certificate::Generate@239] Generating ECDSA P-256 key pair
2022-08-30 16:54:09.116 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Creating agent
2022-08-30 16:54:09.122 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Using random() for random bytes
2022-08-30 16:54:09.123 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Created local description: ufrag="8/1y", pwd="Kw0ONnHlyyU1b1uwWg26ky"
2022-08-30 16:54:09.123 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Generated local SDP description: a=ice-ufrag:8/1y
a=ice-pwd:Kw0ONnHlyyU1b1uwWg26ky
a=ice-options:ice2,trickle

2022-08-30 16:54:09.123 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Assuming controlling mode
2022-08-30 16:54:09.123 DEBUG [1837469] [rtc::impl::PeerConnection::processLocalDescription@948] Adding application to local description, mid="0"
2022-08-30 16:54:09.136 VERB [1837469] [rtc::impl::PeerConnection::processLocalDescription@964] Issuing local description: v=0
o=rtc 2003054121 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:actpass
a=ice-ufrag:8/1y
a=ice-pwd:Kw0ONnHlyyU1b1uwWg26ky
a=ice-options:ice2,trickle
a=fingerprint:sha-256 FF:A9:2B:12:56:01:DC:F1:8D:02:49:C1:3F:48:06:64:A9:8B:46:4B:ED:FB:86:E6:DB:5E:0C:B2:FF:A0:64:3F
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=mid:0
a=sendrecv
a=sctp-port:5000
a=max-message-size:262144

2022-08-30 16:54:09.136 INFO [1837469] [rtc::impl::PeerConnection::changeSignalingState@1182] Changed signaling state to have-local-offer
2022-08-30 16:54:09.136 INFO [1837469] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to in-progress
2022-08-30 16:54:09.136 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Gathering candidates
2022-08-30 16:54:09.136 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Creating connections registry
2022-08-30 16:54:09.136 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Starting connections thread
2022-08-30 16:54:09.136 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Creating connection
FATAL ERROR: HandleScope::HandleScope Entering the V8 API without proper locking in place
1: 0x1058f5205 node::Abort() (.cold.1) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
2: 0x1045f64d9 node::Abort() [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
3: 0x1045f664f node::OnFatalError(char const*, char const*) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
4: 0x10476bbc1 v8::HandleScope::HandleScope(v8::Isolate*) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
2022-08-30 16:54:09.153 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: UDP socket bound to any:57999
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Interrupting connections thread
2022-08-30 16:54:09.154 INFO [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to gathering
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Adding 1 local host candidates
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Gathered host candidate: a=candidate:1 1 UDP 2122317823 10.64.4.254 57999 typ host
2022-08-30 16:54:09.154 VERB [1837469] [rtc::Candidate::parse@100] Parsing candidate: 1 1 UDP 2122317823 xx.xx.xx.xx 57999 typ host
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::PeerConnection::processLocalCandidate@1003] Issuing local candidate: a=candidate:1 1 UDP 2122317823 xx.xx.xx.xx 57999 typ host
2022-08-30 16:54:09.154 VERB [1837469] [rtc::Candidate::resolve@144] Resolving candidate (mode=simple): xx.xx.xx.xx 57999
2022-08-30 16:54:09.154 VERB [1837469] [rtc::Candidate::resolve@179] Resolved candidate: xx.xx.xx.xx 57999
2022-08-30 16:54:09.154 INFO [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to connecting
2022-08-30 16:54:09.154 INFO [1837469] [rtc::impl::PeerConnection::changeState@1151] Changed state to connecting
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Interrupting connections thread
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Resolving servers synchronously
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Updating gathering status
2022-08-30 16:54:09.154 INFO [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Candidate gathering done
2022-08-30 16:54:09.154 INFO [1837469] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to complete
2022-08-30 16:54:09.154 VERB [1837469] [rtc::impl::IceTransport::LogCallback@354] juice: Interrupting connections thread
5: 0x1045b3888 napi_open_handle_scope [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
2022-08-30 16:54:09.155 VERB [1837481] [rtc::impl::IceTransport::LogCallback@354] juice: Entering poll on 1 sockets for 0 ms
2022-08-30 16:54:09.155 VERB [1837481] [rtc::impl::IceTransport::LogCallback@354] juice: Leaving poll
2022-08-30 16:54:09.161 VERB [1837481] [rtc::impl::IceTransport::LogCallback@354] juice: Bookkeeping...
6: 0x111a21623 ThreadSafeCallback::Impl::async_callback() [/Users/oan/github/QuickCafeClient/node_modules/node-datachannel/build/Release/node_datachannel.node]
2022-08-30 16:54:09.164 VERB [1837481] [rtc::impl::IceTransport::LogCallback@354] juice: Entering poll on 1 sockets for 9998 ms
7: 0x111a214ce ThreadSafeCallback::Impl::static_async_callback(uv_async_s*) [/Users/oan/github/QuickCafeClient/node_modules/node-datachannel/build/Release/node_datachannel.node]
8: 0x104fb9aeb uv__async_io [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
9: 0x104fcd8bb uv__io_poll [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
10: 0x104fba071 uv_run [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
11: 0x10452a733 node::SpinEventLoop(node::Environment*) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
12: 0x104635c51 node::NodeMainInstance::Run(int*, node::Environment*) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
13: 0x1046358d3 node::NodeMainInstance::Run() [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
14: 0x1045c3bd2 node::Start(int, char**) [/Users/oan/.volta/tools/image/node/16.17.0/bin/node]
15: 0x1191b24fe

Not use of the support of node-datachannel into a Node worker thread.
@murat-dogan
Copy link
Owner

  • Could you please share your setup, sample code?
  • Are you using docker?

@oanguenot
Copy link
Author

oanguenot commented Aug 31, 2022 •
edited
Loading

HI @murat-dogan, I'm not using Docker.
I use a Mac M1 with Monterey + Node 16.17.0

I have a module which loads a worker:

...
const { Worker } = require("worker_threads");
worker = new Worker("./modules/myWorker.js", { workerData: {} });
worker.postMessage({iceServers1, iceServers2});

Then inside that worker, I load and use node-datachannel to try a connection with 2 peers through a turn server

//myWorker.js
...
let nodeDataChannel = require('node-datachannel');
const { parentPort } = require("worker_threads");

parentPort.on("message", async (data) => {
  try {
  ...
  nodeDataChannel.initLogger("Verbose");
  
  const peer1 = new nodeDataChannel.PeerConnection("Peer1", { iceServers: data.iceServers1, iceTransportPolicy: "relay" });
  const peer2 = new nodeDataChannel.PeerConnection("Peer2", { iceServers: data.iceServers2, iceTransportPolicy: "relay"});
  
  peer1.onLocalDescription((sdp, type) => {
     peer2.setRemoteDescription(sdp, type);
  });
  peer1.onLocalCandidate((candidate, mid) => {
      peer2.addRemoteCandidate(candidate, mid);
  });
  peer2.onLocalDescription((sdp, type) => {
      peer1.setRemoteDescription(sdp, type);
  });
    peer2.onLocalCandidate((candidate, mid) => {
      peer1.addRemoteCandidate(candidate, mid);
  });

  dc1 = peer1.createDataChannel("test");
  dc1.onOpen(() => {
      dc1.sendMessage("Hello from Peer1");
  });
  dc1.onMessage((msg) => {
     ...
  });
  peer2.onDataChannel((dc) => {
      dc2.onMessage((msg) => {
       ...
       });
      dc2.sendMessage("Hello From Peer2");
  });
}

Same code works fine outside a worker.

@paullouisageneau
Copy link
Contributor

@murat-dogan I think it could come from how callbacks are scheduled. Possibly it tries to execute the callback of the worker on the main event loop.

@murat-dogan
Copy link
Owner

@paullouisageneau Normally V8 engine provides isolated environment for all worker_threads as I know.
I made some tests and it really seems about callbacks.

We are still using old napi-thread-safe-callback . Disabling this by deleting LEGACY_NAPI_THREAD_SAFE_CALLBACK makes the trick but comes with an other error. The error is related to package napi-thread-safe-callback-cancellable. But this error does not seem related to worker thread. When I started it as main app, I got the same result.

If we could solve this problem then we can disable legacy mode for node >12

2022-09-01 09:17:10.999 DEBUG [21191] [rtc::impl::Init::doInit@120] Global initialization
2022-09-01 09:17:11.002 DEBUG [21192] [rtc::impl::Certificate::Generate@223] Generating certificate (OpenSSL)
2022-09-01 09:17:11.003 DEBUG [21193] [rtc::impl::Certificate::Generate@223] Generating certificate (OpenSSL)
2022-09-01 09:17:11.003 DEBUG [21191] [rtc::impl::IceTransport::IceTransport@58] Initializing ICE transport (libjuice)
2022-09-01 09:17:11.003 INFO  [21191] [rtc::impl::IceTransport::IceTransport@114] Using STUN server "stun.l.google.com:19302"
2022-09-01 09:17:11.003 DEBUG [21191] [rtc::impl::PeerConnection::processLocalDescription@948] Adding application to local description, mid="0"
2022-09-01 09:17:11.003 INFO  [21191] [rtc::impl::PeerConnection::changeSignalingState@1182] Changed signaling state to have-local-offer
2022-09-01 09:17:11.003 INFO  [21191] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to in-progress
2022-09-01 09:17:11.004 INFO  [21191] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to gathering
2022-09-01 09:17:11.004 INFO  [21191] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to connecting
2022-09-01 09:17:11.004 INFO  [21191] [rtc::impl::PeerConnection::changeState@1151] Changed state to connecting
2022-09-01 09:17:11.006 DEBUG [21191] [rtc::impl::IceTransport::IceTransport@58] Initializing ICE transport (libjuice)
2022-09-01 09:17:11.006 INFO  [21191] [rtc::impl::IceTransport::IceTransport@114] Using STUN server "stun.l.google.com:19302"
2022-09-01 09:17:11.006 INFO  [21191] [rtc::impl::PeerConnection::changeSignalingState@1182] Changed signaling state to have-remote-offer
2022-09-01 09:17:11.006 DEBUG [21191] [rtc::impl::PeerConnection::processLocalDescription@866] Reciprocating application in local description, mid="0"
2022-09-01 09:17:11.007 INFO  [21191] [rtc::impl::PeerConnection::changeSignalingState@1182] Changed signaling state to stable
2022-09-01 09:17:11.007 INFO  [21191] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to in-progress
Peer1 State: connecting
2022-09-01 09:17:11.018 INFO  [21199] [rtc::impl::IceTransport::LogCallback@354] juice: Using STUN server stun.l.google.com:19302
2022-09-01 09:17:11.018 INFO  [21191] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to gathering
2022-09-01 09:17:11.018 INFO  [21191] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to connecting
2022-09-01 09:17:11.018 INFO  [21191] [rtc::impl::PeerConnection::changeState@1151] Changed state to connecting
2022-09-01 09:17:11.019 INFO  [21200] [rtc::impl::IceTransport::LogCallback@354] juice: Using STUN server stun.l.google.com:19302
2022-09-01 09:17:11.020 INFO  [21191] [rtc::impl::PeerConnection::changeSignalingState@1182] Changed signaling state to stable
Peer1 GatheringState: in-progress
Peer1 SDP: v=0
o=rtc 1085502880 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:actpass
a=ice-ufrag:9LTF
a=ice-pwd:3oYE81cpCSTcYPg+VuZu3H
a=ice-options:ice2,trickle
a=fingerprint:sha-256 EB:69:12:B0:1B:C4:4C:7F:1B:22:F9:53:65:4F:02:0F:82:4E:6A:12:29:BD:21:41:F5:01:C6:50:AC:4A:84:56
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=mid:0
a=sendrecv
a=sctp-port:5000
a=max-message-size:262144
  Type: offer
Peer1 Candidate: a=candidate:1 1 UDP 2122317823 10.0.0.93 54008 typ host
Peer1 Candidate: a=candidate:2 1 UDP 2122317567 172.19.0.1 54008 typ host
Peer1 Candidate: a=candidate:3 1 UDP 2122317311 172.18.0.1 54008 typ host
Peer1 Candidate: a=candidate:4 1 UDP 2122317055 172.20.0.1 54008 typ host
Peer1 Candidate: a=candidate:5 1 UDP 2122316799 172.21.0.1 54008 typ host
Peer2 State: connecting
Peer2 GatheringState: in-progress
Peer2 SDP: v=0
o=rtc 2228317412 0 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
a=setup:active
a=ice-ufrag:7L8N
a=ice-pwd:9F4VdPqNQMSmoLy5zlthhN
a=ice-options:ice2,trickle
a=fingerprint:sha-256 B0:D0:7C:5A:38:61:A4:2A:F8:C7:33:31:15:BC:D2:1E:0C:4F:F6:EB:E7:94:22:22:64:06:7E:8E:06:D3:9B:36
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=mid:0
a=sendrecv
a=sctp-port:5000
a=max-message-size:262144
  Type: answer
Peer2 Candidate: a=candidate:1 1 UDP 2122317823 10.0.0.93 42556 typ host
Peer2 Candidate: a=candidate:2 1 UDP 2122317567 172.19.0.1 42556 typ host
Peer2 Candidate: a=candidate:3 1 UDP 2122317311 172.18.0.1 42556 typ host
Peer2 Candidate: a=candidate:4 1 UDP 2122317055 172.20.0.1 42556 typ host
Peer2 Candidate: a=candidate:5 1 UDP 2122316799 172.21.0.1 42556 typ host
2022-09-01 09:17:11.067 WARN  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Send failed, errno=101
2022-09-01 09:17:11.067 WARN  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN message send failed
2022-09-01 09:17:11.068 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN server binding failed
2022-09-01 09:17:11.069 WARN  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Send failed, errno=101
2022-09-01 09:17:11.069 WARN  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN message send failed
2022-09-01 09:17:11.069 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN server binding failed
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN server binding successful
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Got STUN mapped address 88.248.96.126:54008 from server
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Candidate gathering done
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to complete
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: STUN server binding successful
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Got STUN mapped address 88.248.96.126:42556 from server
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Candidate gathering done
2022-09-01 09:17:11.070 INFO  [21198] [rtc::impl::PeerConnection::changeGatheringState@1169] Changed gathering state to complete
Peer1 Candidate: a=candidate:6 1 UDP 1686108927 88.248.96.126 54008 typ srflx raddr 0.0.0.0 rport 0
Peer2 GatheringState: complete
Peer2 Candidate: a=candidate:6 1 UDP 1686108927 88.248.96.126 42556 typ srflx raddr 0.0.0.0 rport 0
Peer1 GatheringState: complete
2022-09-01 09:17:11.118 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to connected
2022-09-01 09:17:11.118 DEBUG [21198] [rtc::impl::DtlsTransport::DtlsTransport@383] Initializing DTLS transport (OpenSSL)
2022-09-01 09:17:11.118 DEBUG [21198] [rtc::impl::DtlsTransport::start@472] Starting DTLS recv thread
2022-09-01 09:17:11.118 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to completed
2022-09-01 09:17:11.419 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to connected
2022-09-01 09:17:11.419 DEBUG [21198] [rtc::impl::DtlsTransport::DtlsTransport@383] Initializing DTLS transport (OpenSSL)
2022-09-01 09:17:11.420 DEBUG [21198] [rtc::impl::DtlsTransport::start@472] Starting DTLS recv thread
2022-09-01 09:17:11.426 INFO  [21201] [rtc::impl::DtlsTransport::runRecvLoop@565] DTLS handshake finished
2022-09-01 09:17:11.426 DEBUG [21201] [rtc::impl::SctpTransport::SctpTransport@189] Initializing SCTP transport
2022-09-01 09:17:11.426 INFO  [21202] [rtc::impl::DtlsTransport::runRecvLoop@565] DTLS handshake finished
2022-09-01 09:17:11.426 DEBUG [21201] [rtc::impl::SctpTransport::connect@371] SCTP connecting (local port=5000, remote port=5000)
2022-09-01 09:17:11.426 DEBUG [21202] [rtc::impl::SctpTransport::SctpTransport@189] Initializing SCTP transport
2022-09-01 09:17:11.427 DEBUG [21202] [rtc::impl::SctpTransport::connect@371] SCTP connecting (local port=5000, remote port=5000)
2022-09-01 09:17:11.428 DEBUG [21194] [rtc::impl::SctpTransport::processNotification@825] SCTP negotiated streams: incoming=1024, outgoing=1024
2022-09-01 09:17:11.428 DEBUG [21193] [rtc::impl::SctpTransport::processNotification@825] SCTP negotiated streams: incoming=1024, outgoing=1024
2022-09-01 09:17:11.429 INFO  [21194] [rtc::impl::SctpTransport::processNotification@830] SCTP connected
2022-09-01 09:17:11.429 INFO  [21193] [rtc::impl::SctpTransport::processNotification@830] SCTP connected
2022-09-01 09:17:11.429 INFO  [21194] [rtc::impl::PeerConnection::changeState@1151] Changed state to connected
2022-09-01 09:17:11.429 INFO  [21193] [rtc::impl::PeerConnection::changeState@1151] Changed state to connected
Peer1 State: connected
Peer2 State: connected
Peer2 Got DataChannel:  test
Peer1 Received Msg: Hello From Peer2
Peer2 Received Msg: Hello from Peer1
2022-09-01 09:17:11.469 INFO  [21198] [rtc::impl::IceTransport::LogCallback@354] juice: Changing state to completed
2022-09-01 09:17:16.010 DEBUG [21195] [rtc::impl::SctpTransport::sendReset@683] SCTP resetting stream 1
2022-09-01 09:17:16.010 INFO  [21191] [rtc::impl::PeerConnection::changeState@1151] Changed state to closed
2022-09-01 09:17:16.010 DEBUG [21193] [rtc::impl::SctpTransport::sendReset@683] SCTP resetting stream 1
2022-09-01 09:17:16.010 INFO  [21191] [rtc::impl::PeerConnection::changeState@1151] Changed state to closed
2022-09-01 09:17:16.010 DEBUG [21194] [rtc::impl::SctpTransport::shutdown@392] SCTP shutdown
2022-09-01 09:17:16.011 INFO  [21194] [rtc::impl::SctpTransport::shutdown@400] SCTP disconnected
2022-09-01 09:17:16.011 DEBUG [21194] [rtc::impl::DtlsTransport::stop@480] Stopping DTLS recv thread
2022-09-01 09:17:16.011 INFO  [21201] [rtc::impl::DtlsTransport::runRecvLoop@612] DTLS closed
2022-09-01 09:17:16.011 INFO  [21193] [rtc::impl::SctpTransport::processNotification@837] SCTP disconnected
2022-09-01 09:17:16.011 DEBUG [21194] [rtc::impl::SctpTransport::shutdown@392] SCTP shutdown
2022-09-01 09:17:16.011 INFO  [21194] [rtc::impl::SctpTransport::shutdown@400] SCTP disconnected
2022-09-01 09:17:16.011 DEBUG [21194] [rtc::impl::DtlsTransport::stop@480] Stopping DTLS recv thread
2022-09-01 09:17:16.011 INFO  [21202] [rtc::impl::DtlsTransport::runRecvLoop@612] DTLS closed
2022-09-01 09:17:16.012 DEBUG [21220] [rtc::impl::Init::doCleanup@158] Global cleanup
FATAL ERROR: Error::New napi_get_last_error_info
 1: 0xb09980 node::Abort() [node]
 2: 0xa1c235 node::FatalError(char const*, char const*) [node]
 3: 0xa1c23e  [node]
 4: 0xad139b napi_fatal_error [node]
 5: 0x7f9f71cfc070 Napi::CallbackScope::~CallbackScope() [/home/murat/js/temp/worker-thread-test/node-datachannel/build/Release/node_datachannel.node]
 6: 0x7f9f71cfc398 Napi::Error::New(napi_env__*) [/home/murat/js/temp/worker-thread-test/node-datachannel/build/Release/node_datachannel.node]
 7: 0x7f9f71ce221f  [/home/murat/js/temp/worker-thread-test/node-datachannel/build/Release/node_datachannel.node]
 8: 0x7f9f71d37875 ThreadSafeCallback::callbackFunc(Napi::Env, Napi::Function, Napi::Reference<Napi::Value>*, ThreadSafeCallback::CallbackData*) [/home/murat/js/temp/worker-thread-test/node-datachannel/build/Release/node_datachannel.node]
 9: 0xacfddc  [node]
10: 0x1563dd1 uv_run [node]
11: 0xa43dd5 node::SpinEventLoop(node::Environment*) [node]
12: 0xbd3262 node::worker::Worker::Run() [node]
13: 0xbd39f8  [node]
14: 0x7f9f8133d609  [/lib/x86_64-linux-gnu/libpthread.so.0]
15: 0x7f9f81262133 clone [/lib/x86_64-linux-gnu/libc.so.6]
Aborted (core dumped)

Could you please check it?

Test env;

// main.js
const { Worker, isMainThread, parentPort } = require('worker_threads');
if (isMainThread) {
  // This code is executed in the main thread and not in the worker.
  
  // Create the worker.
  const worker = new Worker('./worker.js');
  // Listen for messages from the worker and print them.
  worker.on('message', (msg) => { console.log(msg); });
} else {
  // This code is executed in the worker and not in the main thread.
  
  // Send a message to the main thread.
  parentPort.postMessage('Hello world!');
}

// worker.js
// eslint-disable-next-line @typescript-eslint/no-var-requires
const nodeDataChannel = require('./node-datachannel');

nodeDataChannel.initLogger('Debug');
nodeDataChannel.preload();

let dc1 = null;
let dc2 = null;

// Config options
// export interface RtcConfig {
//     iceServers: string[];
//     proxyServer?: ProxyServer;
//     enableIceTcp?: boolean;
//     portRangeBegin?: number;
//     portRangeEnd?: number;
//     maxMessageSize?: number;
//     iceTransportPolicy?: TransportPolicy;
// }
//
// "iceServers" option is an array of stun/turn server urls
// Examples;
// STUN Server Example          : stun:stun.l.google.com:19302
// TURN Server Example          : turn:USERNAME:PASSWORD@TURN_IP_OR_ADDRESS:PORT
// TURN Server Example (TCP)    : turn:USERNAME:PASSWORD@TURN_IP_OR_ADDRESS:PORT?transport=tcp
// TURN Server Example (TLS)    : turns:USERNAME:PASSWORD@TURN_IP_OR_ADDRESS:PORT

let peer1 = new nodeDataChannel.PeerConnection('Peer1', { iceServers: ['stun:stun.l.google.com:19302'] });

// Set Callbacks
peer1.onStateChange((state) => {
    console.log('Peer1 State:', state);
});
peer1.onGatheringStateChange((state) => {
    console.log('Peer1 GatheringState:', state);
});
peer1.onLocalDescription((sdp, type) => {
    console.log('Peer1 SDP:', sdp, ' Type:', type);
    peer2.setRemoteDescription(sdp, type);
});
peer1.onLocalCandidate((candidate, mid) => {
    console.log('Peer1 Candidate:', candidate);
    peer2.addRemoteCandidate(candidate, mid);
});

let peer2 = new nodeDataChannel.PeerConnection('Peer2', { iceServers: ['stun:stun.l.google.com:19302'] });

// Set Callbacks
peer2.onStateChange((state) => {
    console.log('Peer2 State:', state);
});
peer2.onGatheringStateChange((state) => {
    console.log('Peer2 GatheringState:', state);
});
peer2.onLocalDescription((sdp, type) => {
    console.log('Peer2 SDP:', sdp, ' Type:', type);
    peer1.setRemoteDescription(sdp, type);
});
peer2.onLocalCandidate((candidate, mid) => {
    console.log('Peer2 Candidate:', candidate);
    peer1.addRemoteCandidate(candidate, mid);
});
peer2.onDataChannel((dc) => {
    console.log('Peer2 Got DataChannel: ', dc.getLabel());
    dc2 = dc;
    dc2.onMessage((msg) => {
        console.log('Peer2 Received Msg:', msg);
    });
    dc2.sendMessage('Hello From Peer2');
    dc2.onClosed(() => {
        console.log('dc2 closed');
    });
});

// DataChannel Options
// export interface DataChannelInitConfig {
//     protocol?: string;
//     negotiated?: boolean;
//     id?: number;
//     ordered?: boolean;
//     maxPacketLifeTime?: number;
//     maxRetransmits?: number;
// }
dc1 = peer1.createDataChannel('test');
dc1.onOpen(() => {
    dc1.sendMessage('Hello from Peer1');
    // Binary message: Use sendMessageBinary(Buffer)
});
dc1.onMessage((msg) => {
    console.log('Peer1 Received Msg:', msg);
});
dc1.onClosed(() => {
    console.log('dc1 closed');
});

setTimeout(() => {
    dc1.close();
    dc2.close();
    peer1.close();
    peer2.close();
    nodeDataChannel.cleanup();
}, 5 * 1000);

@oanguenot
Copy link
Author

Hi @murat-dogan, sorry, are you expecting a test from my side ? If yes, I will do it quickly

@murat-dogan
Copy link
Owner

Hi
No actually I am still testing.
I found a solution and will release it asap

@murat-dogan
Copy link
Owner

@paullouisageneau
You have commits for js callback hell :)

Could you please check #131 ?
Any comment appreciated.

@oanguenot
If possible could you please pull and test #131?

@paullouisageneau
Copy link
Contributor

@murat-dogan Sorry I didn't have time to check the issue, I'm looking into #131

@murat-dogan
Copy link
Owner

Hi @oanguenot ,

Did you have any chance to test v0.4.0?
Is this issue still exist for you?

@murat-dogan
Copy link
Owner

I am closing this as well.
If you need to please re-open it.

@xurei xurei mentioned this issue Mar 11, 2024
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@oanguenot @paullouisageneau @murat-dogan