Issue on outbound sip call

mobilipia commented 9 years ago

Firstly this is a very great project. It beats all the other webrtc sip product with simplicity and functionality. Its simple enough to get the work done properly without additional overhead. This seems to always happen anytime i try to make an outbound call. Inbound calls are fine and work great. I am using this on ubuntu 14.04. I tried to build for both 32 and 64 bit and the problem persists. Below is the log:

/opt/janus/bin/janus --config=/opt/janus/etc/janus/janus.cfg

Starting Meetecho Janus (WebRTC Gateway) v0.0.6

Reading configuration from /opt/janus/etc/janus/janus.cfg Checking command line arguments... Debug/log level is 4 Adding 'vmnet' to the ICE ignore list... Using myipaddress as local IP... Initializing ICE stuff (IPv6 candidates disabled) Fingerprint of our certificate: C5:5F:DA:7D:84:47:B1:BF:6B:55:16:62:48:31:3E:D3:F1:7B:25:89:92:4A:4B:4D:4D:D9:D5:AF:EA:D8:15:44 Plugins folder: /usr/lib64/janus/plugins Loading plugin 'libjanus_echotest.so'... JANUS EchoTest plugin initialized! Loading plugin 'libjanus_videocall.so'... JANUS VideoCall plugin initialized! Loading plugin 'libjanus_audiobridge.so'... JANUS AudioBridge plugin initialized! Loading plugin 'libjanus_sip.so'... JANUS SIP plugin initialized! Loading plugin 'libjanus_voicemail.so'... JANUS VoiceMail plugin initialized! Loading plugin 'libjanus_streaming.so'... VideoCall watchdog started Echotest watchdog started AudioBridge watchdog started SIP watchdog started VoiceMail watchdog started JANUS Streaming plugin initialized! Loading plugin 'libjanus_videoroom.so'... JANUS VideoRoom plugin initialized! Loading plugin 'libjanus_recordplay.so'... JANUS Record&Play plugin initialized! HTTP webserver started (port 8088, /janus path listener)... Streaming watchdog started VideoRoom watchdog started Record&Play watchdog started [WARN] HTTPS webserver disabled WebSockets server started (port 8188)... [WARN] Secure WebSockets server disabled [WARN] RammitMQ support disabled [WARN] Admin/monitor HTTP webserver disabled [WARN] Admin/monitor HTTPS webserver disabled Sessions watchdog started Creating new session: 3759052905 Creating new handle in session 3759052905: 1358004202 [1358004202] There's a message for JANUS SIP plugin

outbound(0x7f9020002940): FAILED to validate <sip:/opt/janus/bin/janus --config=/opt/janus/etc/janus/janus.cfg

Starting Meetecho Janus (WebRTC Gateway) v0.0.6

Reading configuration from /opt/janus/etc/janus/janus.cfg Checking command line arguments... Debug/log level is 4 Adding 'vmnet' to the ICE ignore list... Using myipaddress as local IP... Initializing ICE stuff (IPv6 candidates disabled) Fingerprint of our certificate: C5:5F:DA:7D:84:47:B1:BF:6B:55:16:62:48:31:3E:D3:F1:7B:25:89:92:4A:4B:4D:4D:D9:D5:AF:EA:D8:15:44 Plugins folder: /usr/lib64/janus/plugins Loading plugin 'libjanus_echotest.so'... JANUS EchoTest plugin initialized! Loading plugin 'libjanus_videocall.so'... JANUS VideoCall plugin initialized! Loading plugin 'libjanus_audiobridge.so'... JANUS AudioBridge plugin initialized! Loading plugin 'libjanus_sip.so'... JANUS SIP plugin initialized! Loading plugin 'libjanus_voicemail.so'... JANUS VoiceMail plugin initialized! Loading plugin 'libjanus_streaming.so'... VideoCall watchdog started Echotest watchdog started AudioBridge watchdog started SIP watchdog started VoiceMail watchdog started JANUS Streaming plugin initialized! Loading plugin 'libjanus_videoroom.so'... JANUS VideoRoom plugin initialized! Loading plugin 'libjanus_recordplay.so'... JANUS Record&Play plugin initialized! HTTP webserver started (port 8088, /janus path listener)... Streaming watchdog started VideoRoom watchdog started Record&Play watchdog started [WARN] HTTPS webserver disabled WebSockets server started (port 8188)... [WARN] Secure WebSockets server disabled [WARN] RammitMQ support disabled [WARN] Admin/monitor HTTP webserver disabled [WARN] Admin/monitor HTTPS webserver disabled Sessions watchdog started Creating new session: 3759052905 Creating new handle in session 3759052905: 1358004202 [1358004202] There's a message for JANUS SIP plugin outbound(0x7f9020002940): FAILED to validate sip:mysipaddress@myipaddress:43522;transport=udp outbound(0x7f9020002940): FAILED with 405 Use sipproxyaddress [1358004202] There's a message for JANUS SIP plugin [1358004202] Creating ICE agent (controlled mode) [1358004202] ICE send thread started... [1358004202] WebRTC resources freed No WebRTC media anymore

(process:11778): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed

(process:11778): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed Segmentation fault (core dumped) ;transport=udp> outbound(0x7f9020002940): FAILED with 405 Use sipproxyaddress [1358004202] There's a message for JANUS SIP plugin [1358004202] Creating ICE agent (controlled mode) [1358004202] ICE send thread started... [1358004202] WebRTC resources freed No WebRTC media anymore

(process:11778): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed

(process:11778): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed Segmentation fault (core dumped)

mobilipia commented 9 years ago

(process:17383): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed

(process:17383): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed janus: ../nptl/pthread_mutex_lock.c:80: pthread_mutex_lock: Assertion `mutex->data.__owner == 0' failed.

Program received signal SIGABRT, Aborted. [Switching to Thread 0x7fffbcff1700 (LWP 17810)] 0x00007ffff53d8bb9 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56 56 ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.

lminiero commented 9 years ago

What's your SIP plugin configuration looking like? What addresses are you registering?

I see errors like FAILED to validate <sip:/opt/janus/bin/janus --config=/opt/janus/etc/janus/janus.cfg, which means that it's the executable that is ending in the SIP address somehow (copy paste errors?), and a FAILED to validate sip:mysipaddress@myipaddress:43522;transport=udp that doesn't make much sense either.

Besides, please don't just paste very long lines of text in comments, as they make the thread (at least for me) hard to follow and unreadable. Put the text somewhere (e.g., pastebin) and just past the link here.

mobilipia commented 9 years ago

Noted. I will put future logs on pastebin. I have a question though. Does the sip demo proxy proxy authentication? i am thinking that the issue may be related to proxy authentication with sip server. Sometimes i get a 407 error when connecting to a third-party sip server.

lminiero commented 9 years ago

It should, as I recall doing some tests with the plugin talking to a Kamailio acting as a proxy towards an Asterisk setup for instance.

gatecrasher777 commented 9 years ago

I'm starting to see a lot of similar errors in the output log

(process:21920): GLib-CRITICAL **: g_async_queue_try_pop: assertion 'queue' failed

ad infinitum.

Although this is with only the videoroom plugin activated. Very hard to isolate and replicate, since it doesn't affect everyone. It seems to be associated with instances when there is a successful negotiation and configuration but video is black and no transmission data appears to be arriving at the server (checked with iftop). For instance webrtc-internals in chrome will even show the video resolution. Just no data packets are received.

ploxiln commented 9 years ago

I've also g_async_queue_try_pop problem, with a plugin based on the videoroom plugin. I thought it was related to a capture stopping while a viewer was viewing, but I can't seem to reproduce it now.

lminiero commented 9 years ago

This is usually not an issue, but just the fact that a deallocated/freed queue has been passed to a g_async_queue_try_pop request, e.g., after a handle has been closed, which means it may be simply a synchronization issue.

If you think that's not the case, or you want to help understand where more precisely is the issue, this may actually happen anywhere a GAsyncQueue is used (the glib error doesn't say that). Without some additional debug that prints the error line when it happens it would be harder to identify. I'm out of the office today, could you try adding some checks on the results of all g_async_queue_try_pop (if they're not already there) and use a LOG_ERR to print an error if it failed (if it doesn't)? I'll try doing the same as soon as I can get back to the code.

ploxiln commented 9 years ago

I figured out where I sometimes see this: the beginning of the loop in janus_ice_send_thread()

void *janus_ice_send_thread(void *data) {
    janus_ice_handle *handle = (janus_ice_handle *)data;
    JANUS_LOG(LOG_INFO, "[%"SCNu64"] ICE send thread started...\n", handle->handle_id);
    janus_ice_queued_packet *pkt = NULL;
    while(!janus_flags_is_set(&handle->webrtc_flags, JANUS_ICE_HANDLE_WEBRTC_ALERT)) {
        pkt = g_async_queue_try_pop(handle->queued_packets);

At least for my case, it seems that thread doesn't coordinate correctly in some cases with janus_ice_webrtc_free(), which is what does

        g_async_queue_unref(handle->queued_packets);
        handle->queued_packets = NULL;

lminiero commented 9 years ago

Good catch, I'll work on a fix tomorrow morning.

lminiero commented 9 years ago

Closing for lack of feedback, as it may have been an issue fixed by #122

meetecho / janus-gateway