[May 15 12:46:37] VERBOSE[8585] logger.c: Asterisk Event Logger restarted [May 15 12:46:37] VERBOSE[8585] logger.c: Asterisk Queue Logger restarted [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> INVITE sip:1@example.com SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-58e443658cb66e45-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1" From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1100v stamp 47069 Content-Length: 952 v=0 o=- 6 2 IN IP4 192.168.0.50 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.0.50 t=0 0 m=audio 56926 RTP/AVP 100 106 6 0 105 8 18 3 5 101 a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=alt:1 1 : V588loRj rGVHkiW0 192.168.0.50 56926 a=sendrecv m=video 36220 RTP/AVP 125 126 115 34 a=x-rtp-session-id:3C66C765BDFEA495FF6F6E3E9DB0686A a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 a=rtpmap:125 H264/90000 a=rtpmap:126 H264/90000 a=rtpmap:115 H263-1998/90000 a=rtpmap:34 H263/90000 a=alt:1 1 : pc6H1bf0 +poWZ84Q 192.168.0.50 36220 a=sendrecv <-------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 0 [ 32]: INVITE sip:1@example.com SIP/2.0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-58e443658cb66e45-1---d8754z-;rport [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 4 [ 26]: To: "1" [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 7 [ 14]: CSeq: 1 INVITE [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 10 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 11 [ 19]: Content-Length: 952 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 12 [ 0]: [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 0 [ 3]: v=0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 1 [ 27]: o=- 6 2 IN IP4 192.168.0.50 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 2 [ 25]: s=CounterPath eyeBeam 1.5 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.0.50 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 4 [ 5]: t=0 0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 5 [ 50]: m=audio 56926 RTP/AVP 100 106 6 0 105 8 18 3 5 101 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 6 [ 51]: a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 7 [ 20]: a=fmtp:18 annexb=yes [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 9 [ 24]: a=rtpmap:100 SPEEX/16000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 10 [ 28]: a=rtpmap:106 SPEEX-FEC/16000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 11 [ 27]: a=rtpmap:105 SPEEX-FEC/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 12 [ 21]: a=rtpmap:18 G729/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 13 [ 33]: a=rtpmap:101 telephone-event/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 14 [ 48]: a=alt:1 1 : V588loRj rGVHkiW0 192.168.0.50 56926 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 16 [ 36]: m=video 36220 RTP/AVP 125 126 115 34 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 17 [ 51]: a=x-rtp-session-id:3C66C765BDFEA495FF6F6E3E9DB0686A [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 18 [ 84]: a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 19 [ 84]: a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 20 [ 46]: a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 21 [ 33]: a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 22 [ 23]: a=rtpmap:125 H264/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 23 [ 23]: a=rtpmap:126 H264/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 24 [ 28]: a=rtpmap:115 H263-1998/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 25 [ 22]: a=rtpmap:34 H263/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 26 [ 48]: a=alt:1 1 : pc6H1bf0 +poWZ84Q 192.168.0.50 36220 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 27 [ 10]: a=sendrecv [May 15 12:46:45] VERBOSE[8335] chan_sip.c: --- (12 headers 28 lines) --- [May 15 12:46:45] DEBUG[8335] acl.c: Found IP address for this socket [May 15 12:46:45] VERBOSE[8335] netsock.c: == Using SIP RTP TOS bits 184 [May 15 12:46:45] VERBOSE[8335] netsock.c: == Using SIP RTP CoS mark 5 [May 15 12:46:45] VERBOSE[8335] netsock.c: == Using SIP VRTP TOS bits 136 [May 15 12:46:45] VERBOSE[8335] netsock.c: == Using SIP VRTP CoS mark 4 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on RTP to Off [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on VRTP to Off [May 15 12:46:45] DEBUG[8335] chan_sip.c: Allocating new SIP dialog for NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. - INVITE (With RTP) [May 15 12:46:45] DEBUG[8335] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Sending to 192.168.0.50 : 24616 (NAT) [May 15 12:46:45] DEBUG[8335] chan_sip.c: Initializing initreq for method INVITE - callid NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Using INVITE request as basis request - NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found peer 'softphone' for 'softphone' from 192.168.0.50:24616 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on RTP to Off [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on VRTP to Off [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.0.50:24616 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-58e443658cb66e45-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1";tag=as2b8a9d30 Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 1 INVITE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0bfa5933" Content-Length: 0 <------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #83 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Trying to put 'SIP/2.0 40' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Scheduling destruction of SIP dialog 'NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU.' in 32000 ms (Method: INVITE) [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> ACK sip:1@example.com SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-58e443658cb66e45-1---d8754z-;rport To: "1";tag=as2b8a9d30 From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 1 ACK Content-Length: 0 <-------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 0 [ 29]: ACK sip:1@example.com SIP/2.0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-58e443658cb66e45-1---d8754z-;rport [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 2 [ 41]: To: "1";tag=as2b8a9d30 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 3 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 4 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 7 [ 0]: [May 15 12:46:45] VERBOSE[8335] chan_sip.c: --- (7 headers 0 lines) --- [May 15 12:46:45] DEBUG[8335] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 15 12:46:45] DEBUG[8335] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #83 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Stopping retransmission on 'NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU.' of Response 1: Match Found [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> INVITE sip:1@example.com SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-fa281c7df942f24a-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1" From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1100v stamp 47069 Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@example.com",response="337607f2984ffdf9f5d67454fa462865",algorithm=MD5 Content-Length: 952 v=0 o=- 6 2 IN IP4 192.168.0.50 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.0.50 t=0 0 m=audio 56926 RTP/AVP 100 106 6 0 105 8 18 3 5 101 a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 a=fmtp:18 annexb=yes a=fmtp:101 0-15 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=alt:1 1 : V588loRj rGVHkiW0 192.168.0.50 56926 a=sendrecv m=video 36220 RTP/AVP 125 126 115 34 a=x-rtp-session-id:3C66C765BDFEA495FF6F6E3E9DB0686A a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 a=rtpmap:125 H264/90000 a=rtpmap:126 H264/90000 a=rtpmap:115 H263-1998/90000 a=rtpmap:34 H263/90000 a=alt:1 1 : pc6H1bf0 +poWZ84Q 192.168.0.50 36220 a=sendrecv <-------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 0 [ 32]: INVITE sip:1@example.com SIP/2.0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-fa281c7df942f24a-1---d8754z-;rport [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 4 [ 26]: To: "1" [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 7 [ 14]: CSeq: 2 INVITE [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 10 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 11 [158]: Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@example.com",response="337607f2984ffdf9f5d67454fa462865",algorithm=MD5 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 12 [ 19]: Content-Length: 952 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 13 [ 0]: [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 0 [ 3]: v=0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 1 [ 27]: o=- 6 2 IN IP4 192.168.0.50 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 2 [ 25]: s=CounterPath eyeBeam 1.5 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.0.50 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 4 [ 5]: t=0 0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 5 [ 50]: m=audio 56926 RTP/AVP 100 106 6 0 105 8 18 3 5 101 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 6 [ 51]: a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 7 [ 20]: a=fmtp:18 annexb=yes [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 9 [ 24]: a=rtpmap:100 SPEEX/16000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 10 [ 28]: a=rtpmap:106 SPEEX-FEC/16000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 11 [ 27]: a=rtpmap:105 SPEEX-FEC/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 12 [ 21]: a=rtpmap:18 G729/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 13 [ 33]: a=rtpmap:101 telephone-event/8000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 14 [ 48]: a=alt:1 1 : V588loRj rGVHkiW0 192.168.0.50 56926 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 16 [ 36]: m=video 36220 RTP/AVP 125 126 115 34 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 17 [ 51]: a=x-rtp-session-id:3C66C765BDFEA495FF6F6E3E9DB0686A [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 18 [ 84]: a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 19 [ 84]: a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 20 [ 46]: a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 21 [ 33]: a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 22 [ 23]: a=rtpmap:125 H264/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 23 [ 23]: a=rtpmap:126 H264/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 24 [ 28]: a=rtpmap:115 H263-1998/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 25 [ 22]: a=rtpmap:34 H263/90000 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 26 [ 48]: a=alt:1 1 : pc6H1bf0 +poWZ84Q 192.168.0.50 36220 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Body 27 [ 10]: a=sendrecv [May 15 12:46:45] VERBOSE[8335] chan_sip.c: --- (13 headers 28 lines) --- [May 15 12:46:45] DEBUG[8335] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Sending to 192.168.0.50 : 24616 (NAT) [May 15 12:46:45] DEBUG[8335] chan_sip.c: Initializing initreq for method INVITE - callid NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Using INVITE request as basis request - NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found peer 'softphone' for 'softphone' from 192.168.0.50:24616 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on RTP to Off [May 15 12:46:45] DEBUG[8335] chan_sip.c: Setting NAT on VRTP to Off [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 100 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 106 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 6 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 0 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 105 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 8 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 18 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 3 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 5 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP audio format 101 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP video format 125 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP video format 126 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP video format 115 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found RTP video format 34 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Peer audio RTP is at port 192.168.0.50:56926 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found audio description format SPEEX for ID 100 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found unknown media description format SPEEX-FEC for ID 106 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found unknown media description format SPEEX-FEC for ID 105 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found audio description format G729 for ID 18 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found audio description format telephone-event for ID 101 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found video description format H264 for ID 125 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found video description format H264 for ID 126 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found video description format H263-1998 for ID 115 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Found video description format H263 for ID 34 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Capabilities: us - 0x38000c (ulaw|alaw|h263|h263p|h264), peer - audio=0x32e (gsm|ulaw|alaw|adpcm|g729|speex)/video=0x380000 (h263|h263p|h264)/text=0x0 (nothing), combined - 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Peer audio RTP is at port 192.168.0.50:56926 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Peer video RTP is at port 192.168.0.50:36220 [May 15 12:46:45] DEBUG[8335] chan_sip.c: We're settling with these formats: 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:45] DEBUG[8335] chan_sip.c: Checking SIP call limits for device softphone [May 15 12:46:45] DEBUG[8335] chan_sip.c: Updating call counter for incoming call [May 15 12:46:45] VERBOSE[8335] chan_sip.c: Looking for 1 in videotest (domain example.com) [May 15 12:46:45] DEBUG[8335] chan_sip.c: *** Our native formats are 0x380004 (ulaw|h263|h263p|h264) [May 15 12:46:45] DEBUG[8335] chan_sip.c: *** Joint capabilities are 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:45] DEBUG[8335] chan_sip.c: *** Our capabilities are 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:45] DEBUG[8335] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 15 12:46:45] DEBUG[8335] chan_sip.c: This channel can handle video! HOLLYWOOD next! [May 15 12:46:45] DEBUG[8335] chan_sip.c: build_route: Contact hop: [May 15 12:46:45] VERBOSE[8335] chan_sip.c: list_route: hop: [May 15 12:46:45] DEBUG[8335] chan_sip.c: SIP/softphone-b7e09758: New call is still down.... Trying... [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- Transmitting (no NAT) to 192.168.0.50:24616 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-fa281c7df942f24a-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1" Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 2 INVITE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:46:45] DEBUG[8310] devicestate.c: No provider found, checking channel drivers for SIP - softphone [May 15 12:46:45] DEBUG[8310] chan_sip.c: Checking device state for peer softphone [May 15 12:46:45] DEBUG[8310] devicestate.c: Changing state for SIP/softphone - state 1 (Not in use) [May 15 12:46:45] DEBUG[8310] devicestate.c: device 'SIP/softphone' state '1' [May 15 12:46:45] DEBUG[8318] app_queue.c: Device 'SIP/softphone' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 15 12:46:45] DEBUG[8812] pbx.c: Launching 'Answer' [May 15 12:46:45] VERBOSE[8812] pbx.c: -- Executing [1@videotest:1] Answer("SIP/softphone-b7e09758", "") in new stack [May 15 12:46:45] DEBUG[8812] chan_sip.c: SIP answering channel: SIP/softphone-b7e09758 [May 15 12:46:45] DEBUG[8812] chan_sip.c: Setting framing from config on incoming call [May 15 12:46:45] DEBUG[8812] chan_sip.c: ** Our capability: 0x38000c (ulaw|alaw|h263|h263p|h264) Video flag: False Text flag: True [May 15 12:46:45] DEBUG[8812] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 15 12:46:45] DEBUG[8812] chan_sip.c: This call needs video offers! [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Audio is at 192.168.0.100 port 15286 [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Video is at 192.168.0.100 port 14362 [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding video codec 0x80000 (h263) to SDP [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding video codec 0x100000 (h263p) to SDP [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding video codec 0x200000 (h264) to SDP [May 15 12:46:45] VERBOSE[8812] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 15 12:46:45] DEBUG[8812] chan_sip.c: -- Done with adding codecs to SDP [May 15 12:46:45] DEBUG[8812] chan_sip.c: Done building SDP. Settling with this capability: 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:45] VERBOSE[8812] chan_sip.c: <--- Reliably Transmitting (no NAT) to 192.168.0.50:24616 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-fa281c7df942f24a-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1";tag=as429fb4c7 Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 2 INVITE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 435 v=0 o=root 805005222 805005222 IN IP4 192.168.0.100 s=Asterisk PBX SVN-branch-1.6.1-r194542 c=IN IP4 192.168.0.100 b=CT:384 t=0 0 m=audio 15286 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 0 RTP/AVP 34 115 125 a=rtpmap:34 H263/90000 a=rtpmap:115 h263-1998/90000 a=rtpmap:125 H264/90000 a=sendrecv <------------> [May 15 12:46:45] DEBUG[8812] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #85 [May 15 12:46:45] DEBUG[8812] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:46:45] DEBUG[8310] devicestate.c: No provider found, checking channel drivers for SIP - softphone [May 15 12:46:45] DEBUG[8310] chan_sip.c: Checking device state for peer softphone [May 15 12:46:45] DEBUG[8310] devicestate.c: Changing state for SIP/softphone - state 1 (Not in use) [May 15 12:46:45] DEBUG[8310] devicestate.c: device 'SIP/softphone' state '1' [May 15 12:46:45] DEBUG[8318] app_queue.c: Device 'SIP/softphone' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 15 12:46:45] DEBUG[8812] rtp.c: Got RTCP report of 132 bytes [May 15 12:46:45] DEBUG[8812] pbx.c: Launching 'Echo' [May 15 12:46:45] VERBOSE[8812] pbx.c: -- Executing [1@videotest:2] Echo("SIP/softphone-b7e09758", "") in new stack [May 15 12:46:45] DEBUG[8812] rtp.c: Ooh, format changed from unknown to ulaw [May 15 12:46:45] DEBUG[8812] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [May 15 12:46:45] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> ACK sip:1@192.168.0.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-3f1fc25f7126a515-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1";tag=as429fb4c7 From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 2 ACK User-Agent: eyeBeam release 1100v stamp 47069 Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@example.com",response="337607f2984ffdf9f5d67454fa462865",algorithm=MD5 Content-Length: 0 <-------------> [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 0 [ 31]: ACK sip:1@192.168.0.100 SIP/2.0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-3f1fc25f7126a515-1---d8754z-;rport [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 4 [ 41]: To: "1";tag=as429fb4c7 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 7 [ 11]: CSeq: 2 ACK [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 8 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 9 [158]: Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@example.com",response="337607f2984ffdf9f5d67454fa462865",algorithm=MD5 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Header 11 [ 0]: [May 15 12:46:45] VERBOSE[8335] chan_sip.c: --- (11 headers 0 lines) --- [May 15 12:46:45] DEBUG[8335] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 15 12:46:45] DEBUG[8335] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #85 [May 15 12:46:45] DEBUG[8335] chan_sip.c: Stopping retransmission on 'NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU.' of Response 2: Match Found [May 15 12:46:48] DEBUG[8812] rtp.c: Got RTCP report of 176 bytes [May 15 12:46:51] DEBUG[8812] rtp.c: Got RTCP report of 176 bytes [May 15 12:46:51] DEBUG[8812] rtp.c: Got RTCP report of 44 bytes [May 15 12:46:51] DEBUG[8812] rtp.c: Unknown RTCP packet (pt=207) received from 192.168.0.50:56927 [May 15 12:46:52] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> <-------------> [May 15 12:46:52] DEBUG[8335] chan_sip.c: Header 0 [ 0]: [May 15 12:46:52] DEBUG[8335] chan_sip.c: Body 0 [ 0]: [May 15 12:46:54] DEBUG[8812] rtp.c: Got RTCP report of 176 bytes [May 15 12:46:56] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> INVITE sip:1@192.168.0.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-ee27e40a12204f7f-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1";tag=as429fb4c7 From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 3 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1100v stamp 47069 Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="b2e46ae38300562e129be8cb47bc43e8",algorithm=MD5 Content-Length: 751 v=0 o=- 6 3 IN IP4 192.168.0.50 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.0.50 t=0 0 m=audio 56926 RTP/AVP 0 8 101 a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv m=video 27548 RTP/AVP 125 126 115 34 a=x-rtp-session-id:54FFB4AC626BEF20B5324F51DA82B436 a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 a=rtpmap:125 H264/90000 a=rtpmap:126 H264/90000 a=rtpmap:115 H263-1998/90000 a=rtpmap:34 H263/90000 a=alt:1 1 : Cc3b4DYT 9PvtyAAE 192.168.0.50 27548 a=sendrecv <-------------> [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 0 [ 34]: INVITE sip:1@192.168.0.100 SIP/2.0 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-ee27e40a12204f7f-1---d8754z-;rport [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 4 [ 41]: To: "1";tag=as429fb4c7 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 7 [ 14]: CSeq: 3 INVITE [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 10 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 11 [160]: Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="b2e46ae38300562e129be8cb47bc43e8",algorithm=MD5 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 12 [ 19]: Content-Length: 751 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Header 13 [ 0]: [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 0 [ 3]: v=0 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 1 [ 27]: o=- 6 3 IN IP4 192.168.0.50 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 2 [ 25]: s=CounterPath eyeBeam 1.5 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.0.50 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 4 [ 5]: t=0 0 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 5 [ 29]: m=audio 56926 RTP/AVP 0 8 101 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 6 [ 51]: a=x-rtp-session-id:1ECB1B4DE027645593DA2850C5709070 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 7 [ 15]: a=fmtp:101 0-15 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 9 [ 10]: a=sendrecv [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 10 [ 36]: m=video 27548 RTP/AVP 125 126 115 34 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 11 [ 51]: a=x-rtp-session-id:54FFB4AC626BEF20B5324F51DA82B436 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 12 [ 84]: a=fmtp:125 profile-level-id=42e00a; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 13 [ 84]: a=fmtp:126 profile-level-id=42e01e; packetization-mode=1; max-br=452; max-mbps=11880 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 14 [ 46]: a=fmtp:115 QCIF=2 CIF=3 I=1 J=1 T=1 MaxBR=4520 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 15 [ 33]: a=fmtp:34 QCIF=2 CIF=3 MaxBR=4520 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 16 [ 23]: a=rtpmap:125 H264/90000 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 17 [ 23]: a=rtpmap:126 H264/90000 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 18 [ 28]: a=rtpmap:115 H263-1998/90000 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 19 [ 22]: a=rtpmap:34 H263/90000 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 20 [ 48]: a=alt:1 1 : Cc3b4DYT 9PvtyAAE 192.168.0.50 27548 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Body 21 [ 10]: a=sendrecv [May 15 12:46:56] VERBOSE[8335] chan_sip.c: --- (13 headers 22 lines) --- [May 15 12:46:56] DEBUG[8335] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Sending to 192.168.0.50 : 24616 (NAT) [May 15 12:46:56] DEBUG[8335] chan_sip.c: Initializing initreq for method INVITE - callid NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP audio format 0 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP audio format 8 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP audio format 101 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP video format 125 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP video format 126 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP video format 115 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found RTP video format 34 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Peer audio RTP is at port 192.168.0.50:56926 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found audio description format telephone-event for ID 101 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Got unsupported a:fmtp in SDP offer [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found video description format H264 for ID 125 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found video description format H264 for ID 126 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found video description format H263-1998 for ID 115 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Found video description format H263 for ID 34 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Capabilities: us - 0x38000c (ulaw|alaw|h263|h263p|h264), peer - audio=0xc (ulaw|alaw)/video=0x380000 (h263|h263p|h264)/text=0x0 (nothing), combined - 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Peer audio RTP is at port 192.168.0.50:56926 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Peer video RTP is at port 192.168.0.50:27548 [May 15 12:46:56] DEBUG[8335] chan_sip.c: We're settling with these formats: 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:56] DEBUG[8335] chan_sip.c: We have an owner, now see if we need to change this call [May 15 12:46:56] DEBUG[8335] chan_sip.c: Got a SIP re-invite for call NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:56] DEBUG[8335] chan_sip.c: SIP/softphone-b7e09758: This call is UP.... [May 15 12:46:56] VERBOSE[8335] chan_sip.c: <--- Transmitting (NAT) to 192.168.0.50:24616 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-ee27e40a12204f7f-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1";tag=as429fb4c7 Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 3 INVITE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 15 12:46:56] DEBUG[8335] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Setting framing from config on incoming call [May 15 12:46:56] DEBUG[8335] chan_sip.c: ** Our capability: 0x38000c (ulaw|alaw|h263|h263p|h264) Video flag: False Text flag: True [May 15 12:46:56] DEBUG[8335] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 15 12:46:56] DEBUG[8335] chan_sip.c: This call needs video offers! [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Audio is at 192.168.0.100 port 15286 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Video is at 192.168.0.100 port 14362 [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding video codec 0x80000 (h263) to SDP [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding video codec 0x100000 (h263p) to SDP [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding video codec 0x200000 (h264) to SDP [May 15 12:46:56] VERBOSE[8335] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 15 12:46:56] DEBUG[8335] chan_sip.c: -- Done with adding codecs to SDP [May 15 12:46:56] DEBUG[8335] chan_sip.c: Done building SDP. Settling with this capability: 0x38000c (ulaw|alaw|h263|h263p|h264) [May 15 12:46:56] VERBOSE[8335] chan_sip.c: <--- Reliably Transmitting (NAT) to 192.168.0.50:24616 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-ee27e40a12204f7f-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1";tag=as429fb4c7 Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 3 INVITE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 435 v=0 o=root 805005222 805005223 IN IP4 192.168.0.100 s=Asterisk PBX SVN-branch-1.6.1-r194542 c=IN IP4 192.168.0.100 b=CT:384 t=0 0 m=audio 15286 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 0 RTP/AVP 34 115 125 a=rtpmap:34 H263/90000 a=rtpmap:115 h263-1998/90000 a=rtpmap:125 H264/90000 a=sendrecv <------------> [May 15 12:46:56] DEBUG[8335] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #87 [May 15 12:46:56] DEBUG[8335] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:46:57] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> ACK sip:1@192.168.0.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-9d1ccd06e6a04a22-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1";tag=as429fb4c7 From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 3 ACK User-Agent: eyeBeam release 1100v stamp 47069 Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="b2e46ae38300562e129be8cb47bc43e8",algorithm=MD5 Content-Length: 0 <-------------> [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 0 [ 31]: ACK sip:1@192.168.0.100 SIP/2.0 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-9d1ccd06e6a04a22-1---d8754z-;rport [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 4 [ 41]: To: "1";tag=as429fb4c7 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 7 [ 11]: CSeq: 3 ACK [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 8 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 9 [160]: Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="b2e46ae38300562e129be8cb47bc43e8",algorithm=MD5 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Header 11 [ 0]: [May 15 12:46:57] VERBOSE[8335] chan_sip.c: --- (11 headers 0 lines) --- [May 15 12:46:57] DEBUG[8335] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 15 12:46:57] DEBUG[8335] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #87 [May 15 12:46:57] DEBUG[8335] chan_sip.c: Stopping retransmission on 'NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU.' of Response 3: Match Found [May 15 12:46:57] DEBUG[8812] rtp.c: Got RTCP report of 176 bytes [May 15 12:46:57] DEBUG[8812] rtp.c: Got RTCP report of 44 bytes [May 15 12:46:57] DEBUG[8812] rtp.c: Unknown RTCP packet (pt=207) received from 192.168.0.50:56927 [May 15 12:47:00] DEBUG[8812] rtp.c: Got RTCP report of 176 bytes [May 15 12:47:00] DEBUG[8812] rtp.c: Got RTCP report of 160 bytes [May 15 12:47:00] VERBOSE[8335] chan_sip.c: <--- SIP read from UDP://192.168.0.50:24616 ---> BYE sip:1@192.168.0.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-e86232083d61f506-1---d8754z-;rport Max-Forwards: 70 Contact: To: "1";tag=as429fb4c7 From: "Softphone";tag=5b24dc4b Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 4 BYE User-Agent: eyeBeam release 1100v stamp 47069 Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="676f580ffe5a9097fe4a89cdc54a1417",algorithm=MD5 Reason: SIP;description="User Hung Up" Content-Length: 0 <-------------> [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 0 [ 31]: BYE sip:1@192.168.0.100 SIP/2.0 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-e86232083d61f506-1---d8754z-;rport [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 3 [ 57]: Contact: [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 4 [ 41]: To: "1";tag=as429fb4c7 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 5 [ 57]: From: "Softphone";tag=5b24dc4b [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 6 [ 53]: Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 7 [ 11]: CSeq: 4 BYE [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 8 [ 45]: User-Agent: eyeBeam release 1100v stamp 47069 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 9 [160]: Authorization: Digest username="softphone",realm="asterisk",nonce="0bfa5933",uri="sip:1@192.168.0.100",response="676f580ffe5a9097fe4a89cdc54a1417",algorithm=MD5 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 10 [ 38]: Reason: SIP;description="User Hung Up" [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [May 15 12:47:00] DEBUG[8335] chan_sip.c: Header 12 [ 0]: [May 15 12:47:00] VERBOSE[8335] chan_sip.c: --- (12 headers 0 lines) --- [May 15 12:47:00] DEBUG[8335] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 15 12:47:00] DEBUG[8335] chan_sip.c: Initializing initreq for method BYE - callid NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:47:00] VERBOSE[8335] chan_sip.c: Sending to 192.168.0.50 : 24616 (NAT) [May 15 12:47:00] DEBUG[8335] chan_sip.c: Setting SIP_ALREADYGONE on dialog NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:47:00] DEBUG[8335] chan_sip.c: Received bye, issuing owner hangup [May 15 12:47:00] VERBOSE[8335] chan_sip.c: <--- Transmitting (NAT) to 192.168.0.50:24616 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.50:24616;branch=z9hG4bK-d8754z-e86232083d61f506-1---d8754z-;received=192.168.0.50;rport=24616 From: "Softphone";tag=5b24dc4b To: "1";tag=as429fb4c7 Call-ID: NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. CSeq: 4 BYE Server: Asterisk PBX SVN-branch-1.6.1-r194542 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Length: 0 <------------> [May 15 12:47:00] DEBUG[8335] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 192.168.0.50:24616 [May 15 12:47:00] DEBUG[8812] pbx.c: Spawn extension (videotest,1,2) exited non-zero on 'SIP/softphone-b7e09758' [May 15 12:47:00] VERBOSE[8812] pbx.c: == Spawn extension (videotest, 1, 2) exited non-zero on 'SIP/softphone-b7e09758' [May 15 12:47:00] DEBUG[8812] channel.c: Soft-Hanging up channel 'SIP/softphone-b7e09758' [May 15 12:47:00] DEBUG[8812] channel.c: Hanging up channel 'SIP/softphone-b7e09758' [May 15 12:47:00] DEBUG[8812] chan_sip.c: Hangup call SIP/softphone-b7e09758, SIP callid NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:47:00] DEBUG[8310] devicestate.c: No provider found, checking channel drivers for SIP - softphone [May 15 12:47:00] DEBUG[8310] chan_sip.c: Checking device state for peer softphone [May 15 12:47:00] DEBUG[8310] devicestate.c: Changing state for SIP/softphone - state 1 (Not in use) [May 15 12:47:00] DEBUG[8310] devicestate.c: device 'SIP/softphone' state '1' [May 15 12:47:00] DEBUG[8318] app_queue.c: Device 'SIP/softphone' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 15 12:47:01] DEBUG[8335] chan_sip.c: Destroying SIP dialog NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU. [May 15 12:47:01] VERBOSE[8335] chan_sip.c: Really destroying SIP dialog 'NTcxMzFlZDNkNzdlOTJjNjBiZDQ1MDY0MjNmMDc0ZmU.' Method: BYE [May 15 12:47:02] VERBOSE[8585] asterisk.c: -- Remote UNIX connection disconnected