[asterisk-users] How to test Websocket support in SIP in Asterisk trunk?

Juan Castro jcastro at instant.com.br
Tue Aug 21 10:46:24 CDT 2012


On Mon, Aug 20, 2012 at 8:20 PM, mailsvb <mailsvb at gmail.com> wrote:
> Hi,
> you need to build Asterisk with SRTP support...
>
> wget http://sourceforge.net/projects/srtp/files/latest/download -O
> srtp-latest.tgz
> tar -zxvf srtp-latest.tgz
> ./configure --prefix=/libsrtp
> make && make install
>
> And for Asterisk...
> ./configure --with-srtp=/libsrtp
>
> this should work...

Recompiled. Well... now at leat in ONE instance the signaling seems to
behave correctly: when I dial from sipml5 to plain SIP. If the
destination is sipml5, the destination browser goes into a funky state
in which the live camera panel pops up but there doesn't seem to be a
recognized ringing state. Here's the log from a sipml5->sipml5 call.
The caller is 2010 and the callee is 2009. (12:40:06 is when I gave up
and clicked "hangup" at the caller.)

(Media? Heh, surely you jest.)

[Aug 21 12:38:25] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:38:35] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 (Checking From) --From tag
wiwN3MEMrB3HGUmlel5V --To-tag
[Aug 21 12:38:35] DEBUG[23469] logger.c: CALL_ID [C-00000002] created by thread.
[Aug 21 12:38:35] DEBUG[23469] acl.c: For destination '192.168.0.92',
our source address is '192.168.0.111'.
[Aug 21 12:38:35] DEBUG[23469] chan_sip.c: Setting SIP_TRANSPORT_WS
with address 192.168.0.111:5060
[Aug 21 12:38:35] DEBUG[23469] chan_sip.c: Allocating new SIP dialog
for e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 - INVITE (No RTP)
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: CALL_ID
[C-00000002] bound to thread.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: **** Received
INVITE (5) - Command in SIP INVITE
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Trying to put
'SIP/2.0 401' onto WS socket destined for 192.168.0.92:5060
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: Call_ID
[C-00000002] being removed from thread.
[Aug 21 12:38:35] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 (Checking From) --From tag
wiwN3MEMrB3HGUmlel5V --To-tag as39a7b995
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: CALL_ID
[C-00000002] bound to thread.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: **** Received
ACK (6) - Command in SIP ACK
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Stopping
retransmission on 'e4d7cda4-c4cb-932f-c084-ac6f87d27eb9' of Response
3106: Match Not Found
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: Call_ID
[C-00000002] being removed from thread.
[Aug 21 12:38:35] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 (Checking From) --From tag
wiwN3MEMrB3HGUmlel5V --To-tag
[Aug 21 12:38:35] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: CALL_ID
[C-00000002] bound to thread.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: **** Received
INVITE (5) - Command in SIP INVITE
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Using engine
'asterisk' for RTP instance '0xb751d8dc'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] res_rtp_asterisk.c:
Allocated port 18704 for RTP instance '0xb751d8dc'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: RTP instance
'0xb751d8dc' is setup and ready to go
[Aug 21 12:38:35] DEBUG[23469][C-00000002] res_rtp_asterisk.c: Setup
RTCP on RTP instance '0xb751d8dc'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] VERBOSE[23469][C-00000002] netsock2.c:   == Using
SIP RTP CoS mark 5
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Setting NAT on RTP to Off
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
session-level SDP v=0... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
session-level SDP o=- 1190078527 1 IN IP4 127.0.0.1... UNSUPPORTED OR
FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
session-level SDP s=webrtc (chrome 22.0.1189.0) - Doubango Telecom
(sipML5 r000)... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
session-level SDP a=group:BUNDLE audio video... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 103 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 104 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 0 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 8 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 106 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 105 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 13 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Setting
payload 126 based on m type on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'189.24.100.229' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'189.24.100.229' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP c=IN IP4 189.24.100.229... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtcp:50445 IN IP4 189.24.100.229...
UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'169.254.103.29' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'169.254.103.29' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:678360110 1 udp 2130714367
169.254.103.29 50910 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'169.254.103.29' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'169.254.103.29' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:678360110 2 udp 2130714367
169.254.103.29 50910 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.92' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.92' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:3473159702 1 udp 2130714367
192.168.0.92 50443 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.92' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.92' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:3473159702 2 udp 2130714367
192.168.0.92 50443 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'189.24.100.229' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'189.24.100.229' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:957632450 1 udp 1912610559
189.24.100.229 50445 typ srflx generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'189.24.100.229' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'189.24.100.229' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:957632450 2 udp 1912610559
189.24.100.229 50445 typ srflx generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'169.254.103.29' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'169.254.103.29' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:1726810334 1 tcp 1694506751
169.254.103.29 9358 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'169.254.103.29' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'169.254.103.29' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:1726810334 2 tcp 1694506751
169.254.103.29 9358 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.92' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.92' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:2173160166 1 tcp 1694506751
192.168.0.92 9359 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.92' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.92' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting '0' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host '0' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=candidate:2173160166 2 tcp 1694506751
192.168.0.92 9359 typ host generation 0... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=ice-ufrag:YLFLCHAxp8K/G2k8... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=ice-pwd:er21jiNVCtNCgWnYRsC8PRGt... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=sendrecv... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=mid:audio... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtcp-mux... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] sip/sdp_crypto.c:
local_key64 evPmckzq1RZ0r2tb1/z/NjQukWKGQ6wUW/P2L+k6 len 40
[Aug 21 12:38:35] DEBUG[23469][C-00000002] res_srtp.c: Adding new
policy for SSRC 1552086667
[Aug 21 12:38:35] DEBUG[23469][C-00000002] sip/sdp_crypto.c: SRTP
policy activated
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80
inline:kKVAuTdky7b3ggE7LJxEh8WOL446Se7Gqrs9ml35 ... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Unsetting
payload 103 on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:103 ISAC/16000... UNSUPPORTED OR
FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Unsetting
payload 104 on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:104 ISAC/32000... UNSUPPORTED OR
FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Unsetting
payload 106 on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:106 CN/32000... UNSUPPORTED OR
FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Unsetting
payload 105 on 0xb6013128
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:105 CN/16000... UNSUPPORTED OR
FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:13 CN/8000... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=rtpmap:126 telephone-event/8000... OK.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=ssrc:458206927 cname:A4TyWC/keKWP1bJr...
UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=ssrc:458206927
mslabel:j150Kmvvvi3IwdKX64kLkvkeBNZNRmUCmIX2... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Processing
media-level (audio) SDP a=ssrc:458206927
label:j150Kmvvvi3IwdKX64kLkvkeBNZNRmUCmIX200... UNSUPPORTED OR FAILED.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] res_rtp_asterisk.c: Setting
RTCP address on RTP instance '0xb751d8dc'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Copying
payload 0 from 0xb6013128 to 0xb751da88
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Copying
payload 8 from 0xb6013128 to 0xb751da88
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Copying
payload 13 from 0xb6013128 to 0xb751da88
[Aug 21 12:38:35] DEBUG[23469][C-00000002] rtp_engine.c: Copying
payload 126 from 0xb6013128 to 0xb751da88
[Aug 21 12:38:35] DEBUG[23469][C-00000002] res_rtp_asterisk.c:
Ignoring duplicate RTCP property on RTP instance '0xb751d8dc'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: We're settling
with these formats: (ulaw|alaw)
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Checking SIP
call limits for device 2010
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Updating call
counter for incoming call
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: *** Our native
formats are (ulaw)
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: *** Joint
capabilities are (ulaw|alaw)
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: *** Our
capabilities are (g723|gsm|ulaw|alaw|g729|ilbc)
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: ***
AST_CODEC_CHOOSE formats are ulaw
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: This channel
will not be able to handle video.
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: build_route:
Contact hop: "Asterisk Ext
2010"<sip:2010 at df7jal23ls0d.invalid;transport=ws>;+sip.ice
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c:
SIP/2010-00000004: New call is still down.... Trying...
[Aug 21 12:38:35] DEBUG[23469][C-00000002] chan_sip.c: Trying to put
'SIP/2.0 100' onto WS socket destined for 192.168.0.92:5060
[Aug 21 12:38:35] DEBUG[22850] devicestate.c: No provider found,
checking channel drivers for SIP - 2010
[Aug 21 12:38:35] DEBUG[22850] chan_sip.c: Checking device state for peer 2010
[Aug 21 12:38:35] DEBUG[22850] devicestate.c: Changing state for
SIP/2010 - state 1 (Not in use)
[Aug 21 12:38:35] DEBUG[22850] devicestate.c: device 'SIP/2010' state '1'
[Aug 21 12:38:35] DEBUG[23469][C-00000002] logger.c: Call_ID
[C-00000002] being removed from thread.
[Aug 21 12:38:35] DEBUG[22886] app_queue.c: Device 'SIP/2010' changed
to state '1' (Not in use) but we don't care because they're not a
member of any queue.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] logger.c: CALL_ID
[C-00000002] bound to thread.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] pbx.c: Result of 'EXTEN' is '2009'
[Aug 21 12:38:35] DEBUG[23498][C-00000002] pbx.c: Launching 'Dial'
[Aug 21 12:38:35] VERBOSE[23498][C-00000002] pbx.c:     -- Executing
[2009 at demo:1] Dial("SIP/2010-00000004", "SIP/2009") in new stack
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Asked to create
a SIP channel with formats: (ulaw)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Allocating new
SIP dialog for 718b1ca10fa799752aef773d65c06d4b@[::1]:5060 - INVITE
(No RTP)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] rtp_engine.c: Using engine
'asterisk' for RTP instance '0xb762321c'
[Aug 21 12:38:35] DEBUG[23498][C-00000002] res_rtp_asterisk.c:
Allocated port 10248 for RTP instance '0xb762321c'
[Aug 21 12:38:35] DEBUG[23498][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23498][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] rtp_engine.c: RTP instance
'0xb762321c' is setup and ready to go
[Aug 21 12:38:35] DEBUG[23498][C-00000002] res_rtp_asterisk.c: Setup
RTCP on RTP instance '0xb762321c'
[Aug 21 12:38:35] DEBUG[23498][C-00000002] netsock2.c: Splitting
'192.168.0.111' into...
[Aug 21 12:38:35] DEBUG[23498][C-00000002] netsock2.c: ...host
'192.168.0.111' and port ''.
[Aug 21 12:38:35] VERBOSE[23498][C-00000002] netsock2.c:   == Using
SIP RTP CoS mark 5
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Setting NAT on RTP to Off
[Aug 21 12:38:35] DEBUG[23498][C-00000002] acl.c: For destination
'192.168.0.101', our source address is '192.168.0.111'.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Setting
SIP_TRANSPORT_WS with address 192.168.0.111:5060
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: *** Our native
formats are (ulaw)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: *** Joint
capabilities are (ulaw)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: *** Our
capabilities are (g723|gsm|ulaw|alaw|g729|ilbc)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: ***
AST_CODEC_CHOOSE formats are ulaw
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: *** Our
preferred formats from the incoming channel are (ulaw)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: This channel
will not be able to handle video.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel_internal_api.c:
Channel Call ID changing from [C-00000002] to [C-00000002]
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable DIALEDTIME.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable ANSWEREDTIME.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable DIALEDPEERNAME.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable DIALEDPEERNUMBER.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable DIALSTATUS.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable SIPCALLID.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable SIPDOMAIN.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] channel.c: Not copying
variable SIPURI.
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Outgoing Call for 2009
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Updating call
counter for outgoing call
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: ** Our
capability: (g723|gsm|ulaw|alaw|g729|ilbc) Video flag: False Text
flag: False
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: ** Our prefcodec: (ulaw)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: -- Done with
adding codecs to SDP
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Done building
SDP. Settling with this capability: (g723|gsm|ulaw|alaw|g729|ilbc)
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Initializing
initreq for method INVITE - callid
6fe146d70776f77366b529645b89ed9d at 192.168.0.111:5060
[Aug 21 12:38:35] DEBUG[23498][C-00000002] chan_sip.c: Trying to put
'INVITE sip:' onto WS socket destined for 192.168.0.101:1374
[Aug 21 12:38:35] VERBOSE[23498][C-00000002] app_dial.c:     -- Called SIP/2009
[Aug 21 12:38:35] DEBUG[23493] chan_sip.c: = Looking for  Call ID:
6fe146d70776f77366b529645b89ed9d at 192.168.0.111:5060 (Checking To)
--From tag as4b273973 --To-tag
[Aug 21 12:38:35] DEBUG[23493][C-00000002] logger.c: CALL_ID
[C-00000002] bound to thread.
[Aug 21 12:38:35] DEBUG[23493][C-00000002] chan_sip.c: SIP response
100 to standard invite
[Aug 21 12:38:35] DEBUG[23493][C-00000002] logger.c: Call_ID
[C-00000002] being removed from thread.
[Aug 21 12:38:40] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 4 instead
[Aug 21 12:38:41] DEBUG[22856] chan_sip.c: Auto destroying SIP dialog
'9daf0199-b570-b044-f61a-06ba32abf748'
[Aug 21 12:38:41] DEBUG[22856] chan_sip.c: Destroying SIP dialog
9daf0199-b570-b044-f61a-06ba32abf748
[Aug 21 12:38:46] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:38:53] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: = Looking for  Call ID:
ecc14f25-12d0-ff34-0918-0ab51486d19c (Checking From) --From tag
oB9dZAcTVxbSTKR1AIJV --To-tag
[Aug 21 12:39:05] DEBUG[23493] acl.c: For destination '192.168.0.101',
our source address is '192.168.0.111'.
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: Setting SIP_TRANSPORT_WS
with address 192.168.0.111:5060
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: Allocating new SIP dialog
for ecc14f25-12d0-ff34-0918-0ab51486d19c - REGISTER (No RTP)
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: **** Received REGISTER (2)
- Command in SIP REGISTER
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: Trying to put 'SIP/2.0 401'
onto WS socket destined for 192.168.0.101:5060
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: = Looking for  Call ID:
ecc14f25-12d0-ff34-0918-0ab51486d19c (Checking From) --From tag
oB9dZAcTVxbSTKR1AIJV --To-tag
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: **** Received REGISTER (2)
- Command in SIP REGISTER
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:05] DEBUG[23493] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: Store REGISTER's
src-IP:port for call routing.
[Aug 21 12:39:05] DEBUG[23493] chan_sip.c: Trying to put 'SIP/2.0 200'
onto WS socket destined for 192.168.0.101:5060
[Aug 21 12:39:05] DEBUG[22850] devicestate.c: No provider found,
checking channel drivers for SIP - 2009
[Aug 21 12:39:05] DEBUG[22850] chan_sip.c: Checking device state for peer 2009
[Aug 21 12:39:05] DEBUG[22850] devicestate.c: Changing state for
SIP/2009 - state 1 (Not in use)
[Aug 21 12:39:05] DEBUG[22850] devicestate.c: device 'SIP/2009' state '1'
[Aug 21 12:39:05] DEBUG[22886] app_queue.c: Device 'SIP/2009' changed
to state '1' (Not in use) but we don't care because they're not a
member of any queue.
[Aug 21 12:39:12] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:39:18] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:39:35] DEBUG[22856] chan_sip.c: Trying to put 'SIP/2.0 183'
onto WS socket destined for 192.168.0.92:5060
[Aug 21 12:39:37] DEBUG[22856] chan_sip.c: Auto destroying SIP dialog
'ecc14f25-12d0-ff34-0918-0ab51486d19c'
[Aug 21 12:39:37] DEBUG[22856] chan_sip.c: Destroying SIP dialog
ecc14f25-12d0-ff34-0918-0ab51486d19c
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
9daf0199-b570-b044-f61a-06ba32abf748 (Checking From) --From tag
IxHmvsATXzQVCDAIM1Fl --To-tag
[Aug 21 12:39:49] DEBUG[23469] acl.c: For destination '192.168.0.92',
our source address is '192.168.0.111'.
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: Setting SIP_TRANSPORT_WS
with address 192.168.0.111:5060
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: Allocating new SIP dialog
for 9daf0199-b570-b044-f61a-06ba32abf748 - REGISTER (No RTP)
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: **** Received REGISTER (2)
- Command in SIP REGISTER
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: Trying to put 'SIP/2.0 401'
onto WS socket destined for 192.168.0.92:5060
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
9daf0199-b570-b044-f61a-06ba32abf748 (Checking From) --From tag
IxHmvsATXzQVCDAIM1Fl --To-tag
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: **** Received REGISTER (2)
- Command in SIP REGISTER
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: Splitting '192.168.0.111' into...
[Aug 21 12:39:49] DEBUG[23469] netsock2.c: ...host '192.168.0.111' and port ''.
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: Store REGISTER's
src-IP:port for call routing.
[Aug 21 12:39:49] DEBUG[23469] chan_sip.c: Trying to put 'SIP/2.0 200'
onto WS socket destined for 192.168.0.92:5060
[Aug 21 12:39:49] DEBUG[22850] devicestate.c: No provider found,
checking channel drivers for SIP - 2010
[Aug 21 12:39:49] DEBUG[22850] chan_sip.c: Checking device state for peer 2010
[Aug 21 12:39:49] DEBUG[22850] devicestate.c: Changing state for
SIP/2010 - state 1 (Not in use)
[Aug 21 12:39:49] DEBUG[22850] devicestate.c: device 'SIP/2010' state '1'
[Aug 21 12:39:49] DEBUG[22886] app_queue.c: Device 'SIP/2010' changed
to state '1' (Not in use) but we don't care because they're not a
member of any queue.
[Aug 21 12:39:54] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 4 instead
[Aug 21 12:40:06] DEBUG[23469] chan_sip.c: = Looking for  Call ID:
e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 (Checking From) --From tag
--To-tag
[Aug 21 12:40:06] DEBUG[23469] chan_sip.c: CANCEL request has no from
tag, dropping callid: e4d7cda4-c4cb-932f-c084-ac6f87d27eb9 from:
<sip:2010 at 192.168.0.111>
[Aug 21 12:40:06] DEBUG[23469] chan_sip.c: Invalid SIP message -
rejected , no callid, len 446
[Aug 21 12:40:07] DEBUG[22872] res_timing_timerfd.c: Expected to
acknowledge 1 ticks but got 6 instead
[Aug 21 12:40:21] DEBUG[22856] chan_sip.c: Auto destroying SIP dialog
'9daf0199-b570-b044-f61a-06ba32abf748'
[Aug 21 12:40:21] DEBUG[22856] chan_sip.c: Destroying SIP dialog
9daf0199-b570-b044-f61a-06ba32abf748



More information about the asterisk-users mailing list