search

slomkowski / mumsi

SIP to Mumble gateway/bridge using PJSUA stack.
Apache License 2.0
41 stars 33 forks source link

Random crashing #8

Open tsolace opened 8 years ago

tsolace commented 8 years ago

Crashes randomly during a call. Same thing happened twice.

concerned@opinions:~/mumsi-dist/mumsi/build$ ./mumsi config.ini 
18:38:39.328 os_core_unix.c !pjlib 2.4.5 for POSIX initialized
18:38:39.329 sip_endpoint.c  .Creating endpoint instance...
18:38:39.329          pjlib  .select() I/O Queue created (0x1d574f0)
18:38:39.330 sip_endpoint.c  .Module "mod-msg-print" registered
18:38:39.330 sip_transport.  .Transport manager created.
18:38:39.330   pjsua_core.c  .PJSUA state changed: NULL --> CREATED
2015-12-12 18:38:39,336 [NOTICE] Pjsua: 18:38:39.335   pjsua_core.c  .pjsua version 2.4.5 for Linux-3.16.0.4/x86_64/glibc-2.19 initialized
2015-12-12 18:40:02,655 [NOTICE] SipCommunicator: Incoming call from "[redacted]" sip:[redacted]@[sipbroker].
terminate called after throwing an instance of 'mumlib::TransportException'
  what():  receive failed: Success
Aborted
slomkowski commented 8 years ago

Please recompile Mumsi with debug log level: edit main.cpp line 18 and change Priority from NOTICE to DEBUG. It'll flood your console. When it crashes, post relevant lines.

tsolace commented 8 years ago

It didn't want to crash for a long time, after I recompiled and ran it, but that's just my luck. It finally did crash, with the same error, but it doesn't look too meaningful, just the same output in the middle of the normal audio packet debug messages.

[begin last 30 lines of output]

2015-12-12 20:16:51,659 [DEBUG] mumlib.Transport: Received 60 B of encoded audio data via TCP.
2015-12-12 20:16:51,659 [INFO] mumlib.Mumlib: Got 60 B of encoded audio data.
2015-12-12 20:16:51,659 [DEBUG] mumlib.Audio: Received 60 B of audio packet, 5 B header, 55 B payload (target: 0, sessionID: 16, seq num: 416116).
2015-12-12 20:16:51,659 [DEBUG] mumlib.Audio: 54 B of Opus data decoded to 480 PCM samples, last packet: 0.
2015-12-12 20:16:51,659 [DEBUG] AudioFramesMixer: Pushing 480 samples to buffer for session 16.
2015-12-12 20:16:51,659 [DEBUG] AudioFramesMixer: Pulling 960 samples from in-buff for session ID 16.
2015-12-12 20:16:51,659 [DEBUG] AudioFramesMixer: Getting 960 mixed samples.
2015-12-12 20:16:51,659 [DEBUG] Pjsua: Calling onIncomingPcmSamples with 960 samples.
2015-12-12 20:16:51,660 [INFO] mumlib.Transport: Sending 134 B of audio data via TCP.
2015-12-12 20:16:51,660 [DEBUG] mumlib.Transport: Sending 140 B of data asynchronously.
2015-12-12 20:16:51,660 [DEBUG] mumlib.Transport: Sent 140 B.
2015-12-12 20:16:51,669 [DEBUG] mumlib.Transport: Received 66 B of data (60 B payload, type 1).
2015-12-12 20:16:51,669 [DEBUG] mumlib.Transport: Received 60 B of encoded audio data via TCP.
2015-12-12 20:16:51,669 [INFO] mumlib.Mumlib: Got 60 B of encoded audio data.
2015-12-12 20:16:51,669 [DEBUG] mumlib.Audio: Received 60 B of audio packet, 5 B header, 55 B payload (target: 0, sessionID: 16,terminate called after throwing an instance of 'mumlib::TransportException'
  what():  receive failed: Success
 seq num: 416117).
2015-12-12 20:16:51,669 [DEBUG] mumlib.Audio: 54 B of Opus data decoded to 480 PCM samples, last packet: 0.
2015-12-12 20:16:51,669 [DEBUG] AudioFramesMixer: Pushing 480 samples to buffer for session 16.
2015-12-12 20:16:51,679 [DEBUG] mumlib.Transport: Received 66 B of data (60 B payload, type 1).
2015-12-12 20:16:51,679 [DEBUG] mumlib.Transport: Received 60 B of encoded audio data via TCP.
2015-12-12 20:16:51,679 [INFO] mumlib.Mumlib: Got 60 B of encoded audio data.
2015-12-12 20:16:51,679 [DEBUG] mumlib.Audio: Received 60 B of audio packet, 5 B header, 55 B payload (target: 0, sessionID: 16, seq num: 416118).
2015-12-12 20:16:51,679 [DEBUG] mumlib.Audio: 54 B of Opus data decoded to 480 PCM samples, last packet: 0.
2015-12-12 20:16:51,679 [DEBUG] AudioFramesMixer: Pushing 480 samples to buffer for session 16.
2015-12-12 20:16:51,679 [DEBUG] AudioFramesMixer: Pulling 960 samples from in-buff for session ID 16.
2015-12-12 20:16:51,679 [DEBUG] AudioFramesMixer: Getting 960 mixed samples.
2015-12-12 20:16:51,679 [DEBUG] Pjsua: Calling onIncomingPcmSamples with 960 samples.
2015-12-12 20:16:51,680 [INFO] mumlib.Transport: Sending 134 B of audio data via TCP.
2015-12-12 20:16:51,680 [DEBUG] mumlib.Transport: Sending 140 B of data asynchronously.

[end of output]

slomkowski commented 8 years ago

I've added additional error message to mumlib. Please pull the change and recompile the project. I think for some reason receive handler triggers with _bytestransferred set to 0.

slomkowski commented 8 years ago

Do you happen to use avatars? I have max message length set to 2048 B.

tsolace commented 8 years ago

The issue still occurs, but this time, it has an SSL "success" error with it:

2015-12-13 16:18:40,626 [ERROR] mumlib.Transport: SSL receiver error: Success. Bytes transferred: 0.
terminate called after throwing an instance of 'mumlib::TransportException'
  what():  receive failed: Success
Aborted
slomkowski commented 8 years ago

I temporarily disabled the exception and commited it to mumlib, branch 6-bytes-transferred, so now it's possible to determine if 0 bytes error causes any harmful behavior.

tsolace commented 8 years ago

Using the 6-bytes-transferred branch now, and I think the issue caused, instead of a crash, for no incoming audio to be sent to the caller (audio from mumble to SIP). Audio sending to mumble continued to work after this glitch.

slomkowski commented 8 years ago

Do you do have have port 64738 UDP enabled in your firewall? I see that audio transfer falls back to TCP for some reason.

tsolace commented 8 years ago

I don't have a firewall, and UDP isn't filtered because the mumble server works. If it helps, the mumble server is on the same machine as mumsi.