Random crashing

[tsolace]

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]

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]

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]

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 bytes_transferred set to 0.

[slomkowski]

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

[tsolace]

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]

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]

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]

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]

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.