[Sep 6 21:00:14] VERBOSE[632] config.c: == Parsing '/etc/asterisk/logger.conf': [Sep 6 21:00:14] DEBUG[632] config.c: Parsing /etc/asterisk/logger.conf [Sep 6 21:00:14] VERBOSE[632] config.c: == Found [Sep 6 21:00:14] VERBOSE[632] logger.c: Asterisk Event Logger restarted [Sep 6 21:00:14] VERBOSE[632] logger.c: Asterisk Queue Logger restarted [Sep 6 21:00:20] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> REGISTER sip:sipzone.tk SIP/2.0 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 94 REGISTER From: "222" ;tag=33c25cb4 To: "222" Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc2f0e0179de303d99f95e80819b1d371363236 Max-Forwards: 70 Authorization: Digest username="222",realm="asterisk",nonce="6d150c39",uri="sip:sipzone.tk",response="27823509ee099828e40d4aeb0c63b168",algorithm=MD5 User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Expires: 3600 Contact: "222" ;expires=3600 Content-Length: 0 <-------------> [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 2 [ 17]: CSeq: 94 REGISTER [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=33c25cb4 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 4 [ 30]: To: "222" [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc2f0e0179de303d99f95e80819b1d371363236 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 7 [149]: Authorization: Digest username="222",realm="asterisk",nonce="6d150c39",uri="sip:sipzone.tk",response="27823509ee099828e40d4aeb0c63b168",algorithm=MD5 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 8 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 9 [ 13]: Expires: 3600 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 10 [ 99]: Contact: "222" ;expires=3600 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:20] VERBOSE[626] chan_sip.c: --- (12 headers 0 lines) --- [Sep 6 21:00:20] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:20] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:20] NOTICE[626] chan_sip.c: Correct auth, but based on stale nonce received from '"222" ;tag=33c25cb4' [Sep 6 21:00:20] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc2f0e0179de303d99f95e80819b1d371363236;received=79.197.197.13 From: "222" ;tag=33c25cb4 To: "222" ;tag=as30710082 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 94 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="46409ea5", stale=true Content-Length: 0 <------------> [Sep 6 21:00:20] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:20] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0' in 32000 ms (Method: REGISTER) [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> REGISTER sip:sipzone.tk SIP/2.0 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 95 REGISTER From: "222" ;tag=33c25cb4 To: "222" Max-Forwards: 70 User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Expires: 3600 Contact: "222" ;expires=3600 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK5a47faa3fa88fabec2ed9d81f675329d363236 Authorization: Digest username="222",realm="asterisk",nonce="46409ea5",uri="sip:sipzone.tk",response="cb84a15f67723feaef5f8356f5887081",algorithm=MD5 Content-Length: 0 <-------------> [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 2 [ 17]: CSeq: 95 REGISTER [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=33c25cb4 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 4 [ 30]: To: "222" [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 6 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 7 [ 13]: Expires: 3600 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 8 [ 99]: Contact: "222" ;expires=3600 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 9 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK5a47faa3fa88fabec2ed9d81f675329d363236 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 10 [149]: Authorization: Digest username="222",realm="asterisk",nonce="46409ea5",uri="sip:sipzone.tk",response="cb84a15f67723feaef5f8356f5887081",algorithm=MD5 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: --- (12 headers 0 lines) --- [Sep 6 21:00:21] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 70dc65d7277aba7d12af1c6a66d36580@178.33.33.224 - OPTIONS (No RTP) [Sep 6 21:00:21] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:21] DEBUG[626] config.c: extract inaddr from [178.33.33.224] gives [178.33.33.224:5060](0) [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Initializing initreq for method OPTIONS - callid 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 0 [ 85]: OPTIONS sip:222@192.168.178.103:5060;transport=udp;registering_acc=sipzone_tk SIP/2.0 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK12bba75c;rport [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as220b9b18 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 4 [ 75]: To: [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 5 [ 37]: Contact: [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 6 [ 55]: Call-ID: 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:21 GMT [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:61299: OPTIONS sip:222@192.168.178.103:5060;transport=udp;registering_acc=sipzone_tk SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK12bba75c;rport Max-Forwards: 70 From: "asterisk" ;tag=as220b9b18 To: Contact: Call-ID: 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:21 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 6 21:00:21] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #73 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK5a47faa3fa88fabec2ed9d81f675329d363236;received=79.197.197.13 From: "222" ;tag=33c25cb4 To: "222" ;tag=as30710082 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 95 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 3600 Contact: ;expires=3600 Date: Mon, 06 Sep 2010 19:00:21 GMT Content-Length: 0 <------------> [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0' in 32000 ms (Method: REGISTER) [Sep 6 21:00:21] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:21] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:21] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:21] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:21] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> SIP/2.0 200 OK To: ;tag=83aaaf6d Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK12bba75c;rport=5060;received=178.33.33.224 CSeq: 102 OPTIONS Call-ID: 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 From: "asterisk" ;tag=as220b9b18 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 <-------------> [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 1 [ 88]: To: ;tag=83aaaf6d [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 2 [ 92]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK12bba75c;rport=5060;received=178.33.33.224 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 3 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 4 [ 55]: Call-ID: 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 5 [ 60]: From: "asterisk" ;tag=as220b9b18 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 6 [ 86]: Contact: "222" [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 7 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 8 [ 80]: Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 9 [ 19]: Allow-Events: refer [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: --- (11 headers 0 lines) --- [Sep 6 21:00:21] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #73 [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Stopping retransmission on '4c10d924106ed0dc7bb7c9f240320205@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:21] DEBUG[626] chan_sip.c: Destroying SIP dialog 4c10d924106ed0dc7bb7c9f240320205@178.33.33.224 [Sep 6 21:00:21] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '4c10d924106ed0dc7bb7c9f240320205@178.33.33.224' Method: OPTIONS [Sep 6 21:00:22] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> <-------------> [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 1 INVITE From: "222" ;tag=177e7855 To: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK2b633d2ff267d7816d00190a53daccf4363236 Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5073 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 460fee11cb0dd27623f08a5bd1872f4a8101a57200a006fee732212ac53cff56 m=video 5075 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 44ac6798b0668b473acfa7235d3090aa9237c6cbf250e1c4871fd82b9584c7d8 <-------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 1 INVITE [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=177e7855 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK2b633d2ff267d7816d00190a53daccf4363236 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 7 [ 86]: Contact: "222" [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 8 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 10 [ 19]: Content-Length: 741 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5073 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 460fee11cb0dd27623f08a5bd1872f4a8101a57200a006fee732212ac53cff56 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5075 RTP/AVP 100 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 44ac6798b0668b473acfa7235d3090aa9237c6cbf250e1c4871fd82b9584c7d8 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: --- (11 headers 24 lines) --- [Sep 6 21:00:30] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:30] VERBOSE[626] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 - INVITE (With RTP) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK2b633d2ff267d7816d00190a53daccf4363236;received=79.197.197.13 From: "222" ;tag=177e7855 To: ;tag=as563e88f8 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 1 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="46509868" Content-Length: 0 <------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #77 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog '5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0' in 6400 ms (Method: INVITE) [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@sipzone.tk SIP/2.0 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "222" ;tag=177e7855 To: ;tag=as563e88f8 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK2b633d2ff267d7816d00190a53daccf4363236 CSeq: 1 ACK Content-Length: 0 <-------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 0 [ 30]: ACK sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=177e7855 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 4 [ 39]: To: ;tag=as563e88f8 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK2b633d2ff267d7816d00190a53daccf4363236 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 6 [ 11]: CSeq: 1 ACK [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:30] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #77 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Stopping retransmission on '5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0' of Response 1: Match Found [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 2 INVITE From: "222" ;tag=177e7855 To: Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK1eea24604a8724dbba61cc1ed2e58776363236 Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5073 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 460fee11cb0dd27623f08a5bd1872f4a8101a57200a006fee732212ac53cff56 m=video 5075 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 44ac6798b0668b473acfa7235d3090aa9237c6cbf250e1c4871fd82b9584c7d8 <-------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 2 INVITE [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=177e7855 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 6 [ 86]: Contact: "222" [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 7 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 9 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK1eea24604a8724dbba61cc1ed2e58776363236 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 10 [153]: Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 11 [ 19]: Content-Length: 741 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5073 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 460fee11cb0dd27623f08a5bd1872f4a8101a57200a006fee732212ac53cff56 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5075 RTP/AVP 100 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 44ac6798b0668b473acfa7235d3090aa9237c6cbf250e1c4871fd82b9584c7d8 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: --- (12 headers 24 lines) --- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing session-level SDP o=222 0 0 IN IP4 192.168.178.103... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.178.103... OK. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 96 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 97 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 0 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 8 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 98 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 99 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 5 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 6 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 15 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP audio format 101 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 96 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 speex/32000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 97 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 speex/16000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format PCMU for ID 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format PCMA for ID 8 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format iLBC for ID 98 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:98 iLBC/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 99 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:99 speex/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 5 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:5 DVI4/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 6 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:6 DVI4/16000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format G728 for ID 15 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:15 G728/8000... OK. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found audio description format telephone-event for ID 101 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=zrtp-hash:1.10 460fee11cb0dd27623f08a5bd1872f4a8101a57200a006fee732212ac53cff56... UNSUPPORTED. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found RTP video format 100 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=recvonly... UNSUPPORTED. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Found video description format H264 for ID 100 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=rtpmap:100 H264/90000... OK. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=fmtp:100 packetization-mode=1... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]]... UNSUPPORTED. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=zrtp-hash:1.10 44ac6798b0668b473acfa7235d3090aa9237c6cbf250e1c4871fd82b9584c7d8... UNSUPPORTED. [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x62c (ulaw|alaw|adpcm|speex|ilbc)/video=0x200000 (h264)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Peer audio RTP is at port 192.168.178.103:5073 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Checking SIP call limits for device 222 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Updating call counter for incoming call [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: Looking for 111 in Sip-Out (domain sipzone.tk) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:30] DEBUG[626] chan_sip.c: build_route: Contact hop: "222" [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: list_route: hop: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: SIP/222-00000004: New call is still down.... Trying... [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK1eea24604a8724dbba61cc1ed2e58776363236;received=79.197.197.13 From: "222" ;tag=177e7855 To: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:30] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:30] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:30] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:30] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:30] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:30] DEBUG[737] pbx.c: Launching 'Set' [Sep 6 21:00:30] VERBOSE[737] pbx.c: -- Executing [111@Sip-Out:1] Set("SIP/222-00000004", "NR=111") in new stack [Sep 6 21:00:30] DEBUG[737] pbx.c: Launching 'Wait' [Sep 6 21:00:30] VERBOSE[737] pbx.c: -- Executing [111@Sip-Out:2] Wait("SIP/222-00000004", "100") in new stack [Sep 6 21:00:30] DEBUG[704] manager.c: Manager received command 'Redirect' [Sep 6 21:00:30] DEBUG[704] channel.c: Soft-Hanging up channel 'SIP/222-00000004' [Sep 6 21:00:30] DEBUG[737] pbx.c: Spawn extension (initCall,s,1) exited non-zero on 'SIP/222-00000004' [Sep 6 21:00:30] VERBOSE[737] pbx.c: == Spawn extension (initCall, s, 1) exited non-zero on 'SIP/222-00000004' [Sep 6 21:00:30] DEBUG[737] pbx.c: Launching 'Dial' [Sep 6 21:00:30] VERBOSE[737] pbx.c: -- Executing [s@initCall:1] Dial("SIP/222-00000004", "SIP/111,,M(Timeout)") in new stack [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Sep 6 21:00:30] VERBOSE[737] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Allocating new SIP dialog for 639541ff3f4ce43066f69b2438dbea56@178.33.33.224 - INVITE (With RTP) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:30] DEBUG[737] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 6 21:00:30] DEBUG[737] acl.c: Found IP address for this socket [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable DIALEDTIME. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable ANSWEREDTIME. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable DIALEDPEERNAME. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable DIALEDPEERNUMBER. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable DIALSTATUS. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable NR. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable SIPCALLID. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable SIPDOMAIN. [Sep 6 21:00:30] DEBUG[737] channel.c: Not copying variable SIPURI. [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Outgoing Call for 111 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Updating call counter for outgoing call [Sep 6 21:00:30] DEBUG[737] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Sep 6 21:00:30] DEBUG[737] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Sep 6 21:00:30] VERBOSE[737] chan_sip.c: Audio is at 178.33.33.224 port 10730 [Sep 6 21:00:30] VERBOSE[737] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Sep 6 21:00:30] VERBOSE[737] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Sep 6 21:00:30] VERBOSE[737] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 6 21:00:30] DEBUG[737] chan_sip.c: -- Done with adding codecs to SDP [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Initializing initreq for method INVITE - callid 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 0 [ 75]: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 3 [ 49]: From: "imox" ;tag=as4d787327 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 4 [ 66]: To: [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 5 [ 30]: Contact: [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 6 [ 55]: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:30 GMT [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Sep 6 21:00:30] VERBOSE[737] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport Max-Forwards: 70 From: "imox" ;tag=as4d787327 To: Contact: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 288 v=0 o=root 398700144 398700144 IN IP4 178.33.33.224 s=Asterisk PBX 1.6.2.11 c=IN IP4 178.33.33.224 t=0 0 m=audio 10730 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 --- [Sep 6 21:00:30] DEBUG[737] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #80 [Sep 6 21:00:30] DEBUG[737] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:30] VERBOSE[737] app_dial.c: -- Called 111 [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 100 Trying From: "imox" ;tag=as4d787327 Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport To: Content-Length: 0 <-------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4d787327 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 5 [ 66]: To: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 7 [ 0]: [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: --- (7 headers 0 lines) --- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: *** SIP TIMER: Cancelling retransmission #80 - INVITE (got response) [Sep 6 21:00:30] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' Request 102: Found [Sep 6 21:00:30] DEBUG[626] chan_sip.c: SIP response 100 to standard invite [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 180 Ringing From: "imox" ;tag=as4d787327 Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4d787327 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:30] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:30] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:30] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' Request 102: Found [Sep 6 21:00:30] DEBUG[626] chan_sip.c: SIP response 180 to standard invite [Sep 6 21:00:30] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:30] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:30] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:30] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:31] VERBOSE[737] app_dial.c: -- SIP/111-00000005 is ringing [Sep 6 21:00:31] VERBOSE[737] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK1eea24604a8724dbba61cc1ed2e58776363236;received=79.197.197.13 From: "222" ;tag=177e7855 To: ;tag=as2829d8d4 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:31] DEBUG[737] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:31] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:33] WARNING[737] rtp.c: RTP Read too short [Sep 6 21:00:33] DEBUG[737] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 79.197.197.13:23343 [Sep 6 21:00:33] DEBUG[737] rtp.c: Got RTCP report of 4 bytes [Sep 6 21:00:33] DEBUG[737] rtp.c: Unknown RTCP packet (pt=0) received from 79.197.197.13:23343 [Sep 6 21:00:33] DEBUG[737] rtp.c: Got RTCP report of 36 bytes [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 200 OK From: "imox" ;tag=as4d787327 Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Type: application/sdp Content-Length: 196 v=0 o=- 29352 37392 IN IP4 192.168.178.141 s=bdorfek c=IN IP4 192.168.178.141 t=0 0 m=audio 23342 RTP/AVP 0 8 101 a=rtpmap:101 TELEPHONE-EVENT/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4d787327 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK113a763c;rport [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 10 [ 19]: Content-Length: 196 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 1 [ 38]: o=- 29352 37392 IN IP4 192.168.178.141 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 2 [ 9]: s=bdorfek [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.141 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 5 [ 29]: m=audio 23342 RTP/AVP 0 8 101 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 6 [ 33]: a=rtpmap:101 TELEPHONE-EVENT/8000 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 7 [ 15]: a=fmtp:101 0-15 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 8 [ 10]: a=ptime:20 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Body 9 [ 10]: a=sendrecv [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: --- (11 headers 10 lines) --- [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Acked pending invite 102 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Stopping retransmission on '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:33] DEBUG[626] chan_sip.c: SIP response 200 to standard invite [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing session-level SDP o=- 29352 37392 IN IP4 192.168.178.141... UNSUPPORTED. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing session-level SDP s=bdorfek... UNSUPPORTED. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.178.141... OK. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Found RTP audio format 0 [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Found RTP audio format 8 [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Found RTP audio format 101 [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Found audio description format TELEPHONE-EVENT for ID 101 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 TELEPHONE-EVENT/8000... OK. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Peer audio RTP is at port 192.168.178.141:23342 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Sep 6 21:00:33] DEBUG[626] chan_sip.c: We have an owner, now see if we need to change this call [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Updating call counter for outgoing call [Sep 6 21:00:33] DEBUG[626] chan_sip.c: build_route: Contact hop: [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: list_route: hop: [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Strict routing enforced for session 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: set_destination: Parsing for address/port to send to [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: set_destination: set destination to 192.168.178.141, port 41830 [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: Transmitting (NAT) to 79.197.197.13:41830: ACK sip:111@192.168.178.141:41830 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK199f4692;rport Max-Forwards: 70 From: "imox" ;tag=as4d787327 To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 Contact: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.11 Content-Length: 0 --- [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Trying to put 'ACK sip:111' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:33] VERBOSE[737] app_dial.c: -- SIP/111-00000005 answered SIP/222-00000004 [Sep 6 21:00:33] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:33] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:33] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:33] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:33] DEBUG[737] pbx.c: Launching 'Set' [Sep 6 21:00:33] VERBOSE[737] pbx.c: -- Executing [s@macro-Timeout:1] Set("SIP/111-00000005", "TIMEOUT(absolute)=16") in new stack [Sep 6 21:00:33] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:33] VERBOSE[737] func_timeout.c: Channel will hangup at 2010-09-06 21:00:49.675 CEST. [Sep 6 21:00:33] DEBUG[737] app_macro.c: Executed application: Set [Sep 6 21:00:33] DEBUG[737] app_dial.c: Macro exited with status 0 [Sep 6 21:00:33] DEBUG[737] chan_sip.c: SIP answering channel: SIP/222-00000004 [Sep 6 21:00:33] DEBUG[737] rtp.c: Setting the marker bit due to a source update [Sep 6 21:00:33] DEBUG[737] chan_sip.c: Setting framing from config on incoming call [Sep 6 21:00:33] DEBUG[737] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: True [Sep 6 21:00:33] DEBUG[737] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Sep 6 21:00:33] VERBOSE[737] chan_sip.c: Audio is at 178.33.33.224 port 17420 [Sep 6 21:00:33] VERBOSE[737] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Sep 6 21:00:33] VERBOSE[737] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Sep 6 21:00:33] VERBOSE[737] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 6 21:00:33] DEBUG[737] chan_sip.c: -- Done with adding codecs to SDP [Sep 6 21:00:33] DEBUG[737] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Sep 6 21:00:33] VERBOSE[737] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK1eea24604a8724dbba61cc1ed2e58776363236;received=79.197.197.13 From: "222" ;tag=177e7855 To: ;tag=as2829d8d4 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 313 v=0 o=root 1335341484 1335341484 IN IP4 178.33.33.224 s=Asterisk PBX 1.6.2.11 c=IN IP4 178.33.33.224 t=0 0 m=audio 17420 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 100 <------------> [Sep 6 21:00:33] DEBUG[737] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #83 [Sep 6 21:00:33] DEBUG[737] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:33] DEBUG[737] features.c: bridge answer set, chan answer set [Sep 6 21:00:33] DEBUG[737] rtp.c: Setting the marker bit due to a source update [Sep 6 21:00:33] DEBUG[737] rtp.c: Setting the marker bit due to a source update [Sep 6 21:00:33] VERBOSE[737] rtp.c: -- Packet2Packet bridging SIP/222-00000004 and SIP/111-00000005 [Sep 6 21:00:33] DEBUG[737] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 79.197.197.13:23343 [Sep 6 21:00:33] DEBUG[737] rtp.c: Got RTCP report of 4 bytes [Sep 6 21:00:33] DEBUG[737] rtp.c: Unknown RTCP packet (pt=0) received from 79.197.197.13:23343 [Sep 6 21:00:33] WARNING[737] rtp.c: RTP Read too short [Sep 6 21:00:33] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:33] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:33] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:33] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:33] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:33] DEBUG[704] manager.c: Manager received command 'AbsoluteTimeout' [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@178.33.33.224 SIP/2.0 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 2 ACK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK65c3498c137cfe329ca2cfa06b01d086363236 From: "222" ;tag=177e7855 To: ;tag=as2829d8d4 Max-Forwards: 70 Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Length: 0 <-------------> [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 0 [ 33]: ACK sip:111@178.33.33.224 SIP/2.0 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 2 [ 11]: CSeq: 2 ACK [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 3 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK65c3498c137cfe329ca2cfa06b01d086363236 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 4 [ 45]: From: "222" ;tag=177e7855 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 5 [ 39]: To: ;tag=as2829d8d4 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 7 [153]: Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 8 [ 86]: Contact: "222" [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 9 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:33] VERBOSE[626] chan_sip.c: --- (11 headers 0 lines) --- [Sep 6 21:00:33] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:33] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #83 [Sep 6 21:00:33] DEBUG[626] chan_sip.c: Stopping retransmission on '5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0' of Response 2: Match Found [Sep 6 21:00:34] DEBUG[737] rtp.c: RTP NAT: Got audio from other end. Now sending to address 79.197.197.13:23342 [Sep 6 21:00:34] DEBUG[737] rtp.c: RTP NAT: Got audio from other end. Now sending to address 79.197.197.13:5073 [Sep 6 21:00:34] DEBUG[737] rtp.c: Runt Attribute (got 1, expecting 4) [Sep 6 21:00:34] DEBUG[737] rtp.c: Runt Attribute (got 2, expecting 4) [Sep 6 21:00:34] DEBUG[737] rtp.c: Runt Attribute (got 3, expecting 4) [Sep 6 21:00:34] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 4) [Sep 6 21:00:34] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 5) [Sep 6 21:00:34] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 6) [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> REGISTER sip:sipzone.tk SIP/2.0 Max-Forwards: 70 From: ;tag=66D34875CB8598A156F965D343464517 Contact: Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE Supported: replaces User-Agent: Acrobits Softphone/4.1 To: Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 Expires: 600 CSeq: 14227 REGISTER Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bKgVqyOb57aP81eFA5;rport Authorization: Digest username="111", realm="asterisk", algorithm=MD5, uri="sip:sipzone.tk", nonce="3b1578a2", response="bcaf434a2353eb434f35dd40b03cb62a" Content-Length: 0 <-------------> [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 1 [ 16]: Max-Forwards: 70 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 2 [ 63]: From: ;tag=66D34875CB8598A156F965D343464517 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 3 [ 71]: Contact: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 4 [ 47]: Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 5 [ 19]: Supported: replaces [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 6 [ 34]: User-Agent: Acrobits Softphone/4.1 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 7 [ 24]: To: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 8 [ 49]: Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 9 [ 12]: Expires: 600 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 10 [ 20]: CSeq: 14227 REGISTER [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 11 [ 75]: Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bKgVqyOb57aP81eFA5;rport [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 12 [154]: Authorization: Digest username="111", realm="asterisk", algorithm=MD5, uri="sip:sipzone.tk", nonce="3b1578a2", response="bcaf434a2353eb434f35dd40b03cb62a" [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 14 [ 0]: [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: --- (14 headers 0 lines) --- [Sep 6 21:00:35] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:35] DEBUG[626] config.c: extract inaddr from [178.33.33.224] gives [178.33.33.224:5060](0) [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Allocating new SIP dialog for D0ACB55A940084962A0A3E50B1F835CC1D519EC4 - REGISTER (No RTP) [Sep 6 21:00:35] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid D0ACB55A940084962A0A3E50B1F835CC1D519EC4 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 41830 (NAT) [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:41830 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bKgVqyOb57aP81eFA5;received=79.197.197.13;rport=41830 From: ;tag=66D34875CB8598A156F965D343464517 To: ;tag=as689d180d Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 CSeq: 14227 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="276ea3b6" Content-Length: 0 <------------> [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'D0ACB55A940084962A0A3E50B1F835CC1D519EC4' in 32000 ms (Method: REGISTER) [Sep 6 21:00:35] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 7) [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> REGISTER sip:sipzone.tk SIP/2.0 Max-Forwards: 70 From: ;tag=66D34875CB8598A156F965D343464517 Contact: Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE Supported: replaces User-Agent: Acrobits Softphone/4.1 To: Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 Expires: 600 CSeq: 14228 REGISTER Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bK9CAS284XmHFp1hc0;rport Authorization: Digest username="111", realm="asterisk", algorithm=MD5, uri="sip:sipzone.tk", nonce="276ea3b6", response="9001a792ba98798d70c852910b4670dd" Content-Length: 0 <-------------> [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 1 [ 16]: Max-Forwards: 70 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 2 [ 63]: From: ;tag=66D34875CB8598A156F965D343464517 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 3 [ 71]: Contact: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 4 [ 47]: Allow: OPTIONS, INVITE, ACK, REFER, CANCEL, BYE [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 5 [ 19]: Supported: replaces [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 6 [ 34]: User-Agent: Acrobits Softphone/4.1 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 7 [ 24]: To: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 8 [ 49]: Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 9 [ 12]: Expires: 600 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 10 [ 20]: CSeq: 14228 REGISTER [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 11 [ 75]: Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bK9CAS284XmHFp1hc0;rport [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 12 [154]: Authorization: Digest username="111", realm="asterisk", algorithm=MD5, uri="sip:sipzone.tk", nonce="276ea3b6", response="9001a792ba98798d70c852910b4670dd" [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 14 [ 0]: [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: --- (14 headers 0 lines) --- [Sep 6 21:00:35] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid D0ACB55A940084962A0A3E50B1F835CC1D519EC4 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 41830 (NAT) [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 0b11cff32d2f831f55a22bc861060f18@178.33.33.224 - OPTIONS (No RTP) [Sep 6 21:00:35] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Initializing initreq for method OPTIONS - callid 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 0 [ 76]: OPTIONS sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK6bf1d8fd;rport [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as7de661d4 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 4 [ 66]: To: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 5 [ 37]: Contact: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 6 [ 55]: Call-ID: 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:35 GMT [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: OPTIONS sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK6bf1d8fd;rport Max-Forwards: 70 From: "asterisk" ;tag=as7de661d4 To: Contact: Call-ID: 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:35 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 6 21:00:35] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #86 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: > Saved useragent "Acrobits Softphone/4.1" for peer 111 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:41830 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.141:41830;branch=z9hG4bK9CAS284XmHFp1hc0;received=79.197.197.13;rport=41830 From: ;tag=66D34875CB8598A156F965D343464517 To: ;tag=as689d180d Call-ID: D0ACB55A940084962A0A3E50B1F835CC1D519EC4 CSeq: 14228 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 600 Contact: ;expires=600 Date: Mon, 06 Sep 2010 19:00:35 GMT Content-Length: 0 <------------> [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'D0ACB55A940084962A0A3E50B1F835CC1D519EC4' in 32000 ms (Method: REGISTER) [Sep 6 21:00:35] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:35] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:35] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:35] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:35] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 200 OK From: "asterisk" ;tag=as7de661d4 Call-ID: 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK6bf1d8fd;rport To: Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Accept: application/sdp Content-Length: 0 <-------------> [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 1 [ 60]: From: "asterisk" ;tag=as7de661d4 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 3 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK6bf1d8fd;rport [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 5 [ 66]: To: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: --- (11 headers 0 lines) --- [Sep 6 21:00:35] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #86 [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Stopping retransmission on '4ed6c04d2f57d0760f197580554d944c@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:35] DEBUG[626] chan_sip.c: Destroying SIP dialog 4ed6c04d2f57d0760f197580554d944c@178.33.33.224 [Sep 6 21:00:35] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '4ed6c04d2f57d0760f197580554d944c@178.33.33.224' Method: OPTIONS [Sep 6 21:00:35] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 8) [Sep 6 21:00:35] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 9) [Sep 6 21:00:35] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 10) [Sep 6 21:00:35] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 11) [Sep 6 21:00:36] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 12) [Sep 6 21:00:36] DEBUG[737] rtp.c: Got RTCP report of 124 bytes [Sep 6 21:00:36] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 13) [Sep 6 21:00:36] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 14) [Sep 6 21:00:36] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 15) [Sep 6 21:00:36] DEBUG[737] rtp.c: Got RTCP report of 80 bytes [Sep 6 21:00:36] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 16) [Sep 6 21:00:37] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 17) [Sep 6 21:00:37] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 18) [Sep 6 21:00:37] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 19) [Sep 6 21:00:37] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 20) [Sep 6 21:00:37] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 21) [Sep 6 21:00:38] DEBUG[737] rtp.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 22) [Sep 6 21:00:39] DEBUG[737] rtp.c: Got RTCP report of 88 bytes [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> BYE sip:111@178.33.33.224 SIP/2.0 CSeq: 3 BYE From: "222" ;tag=177e7855 To: ;tag=as2829d8d4 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 Max-Forwards: 70 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKe74850078bdab1309b7d57971b59da77363236 Contact: "222" Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Length: 0 <-------------> [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 0 [ 33]: BYE sip:111@178.33.33.224 SIP/2.0 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 1 [ 11]: CSeq: 3 BYE [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 2 [ 45]: From: "222" ;tag=177e7855 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 3 [ 39]: To: ;tag=as2829d8d4 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 4 [ 57]: Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 6 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKe74850078bdab1309b7d57971b59da77363236 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 7 [ 86]: Contact: "222" [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 8 [153]: Authorization: Digest username="222",realm="asterisk",nonce="46509868",uri="sip:111@sipzone.tk",response="192a086d2ef4f20ce4a7dcb31826df22",algorithm=MD5 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 9 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: --- (11 headers 0 lines) --- [Sep 6 21:00:40] DEBUG[626] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Initializing initreq for method BYE - callid 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Setting SIP_ALREADYGONE on dialog 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Received bye, issuing owner hangup [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKe74850078bdab1309b7d57971b59da77363236;received=79.197.197.13 From: "222" ;tag=177e7855 To: ;tag=as2829d8d4 Call-ID: 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 CSeq: 3 BYE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:40] DEBUG[737] rtp.c: p2p-rtp-bridge: Ooh, got a hangup [Sep 6 21:00:40] DEBUG[737] channel.c: Returning from native bridge, channels: SIP/222-00000004, SIP/111-00000005 [Sep 6 21:00:40] DEBUG[737] channel.c: Hanging up channel 'SIP/111-00000005' [Sep 6 21:00:40] DEBUG[737] chan_sip.c: Hangup call SIP/111-00000005, SIP callid 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:40] VERBOSE[737] chan_sip.c: Scheduling destruction of SIP dialog '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' in 13312 ms (Method: INVITE) [Sep 6 21:00:40] DEBUG[737] chan_sip.c: Strict routing enforced for session 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:40] VERBOSE[737] chan_sip.c: set_destination: Parsing for address/port to send to [Sep 6 21:00:40] VERBOSE[737] chan_sip.c: set_destination: set destination to 192.168.178.141, port 41830 [Sep 6 21:00:40] VERBOSE[737] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: BYE sip:111@192.168.178.141:41830 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK560f419e;rport Max-Forwards: 70 From: "imox" ;tag=as4d787327 To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 103 BYE User-Agent: Asterisk PBX 1.6.2.11 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Sep 6 21:00:40] DEBUG[737] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #91 [Sep 6 21:00:40] DEBUG[737] chan_sip.c: Trying to put 'BYE sip:111' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:40] DEBUG[737] rtp.c: Channel '' has no RTP, not doing anything [Sep 6 21:00:40] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:40] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:40] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:40] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:40] DEBUG[737] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Sep 6 21:00:40] DEBUG[737] pbx.c: Spawn extension (initCall,s,1) exited non-zero on 'SIP/222-00000004' [Sep 6 21:00:40] VERBOSE[737] pbx.c: == Spawn extension (initCall, s, 1) exited non-zero on 'SIP/222-00000004' [Sep 6 21:00:40] DEBUG[737] channel.c: Soft-Hanging up channel 'SIP/222-00000004' [Sep 6 21:00:40] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:40] DEBUG[737] channel.c: Hanging up channel 'SIP/222-00000004' [Sep 6 21:00:40] DEBUG[737] chan_sip.c: Hangup call SIP/222-00000004, SIP callid 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:40] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:40] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:40] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:40] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:40] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Destroying SIP dialog 5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0 [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '5b80213c66e128c8de9cb2bdc4f963e9@0:0:0:0:0:0:0:0' Method: BYE [Sep 6 21:00:40] DEBUG[704] manager.c: Manager received command 'Hangup' [Sep 6 21:00:40] DEBUG[704] manager.c: Manager received command 'Hangup' [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 200 OK From: "imox" ;tag=as4d787327 Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 CSeq: 103 BYE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK560f419e;rport To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4d787327 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 3 [ 13]: CSeq: 103 BYE [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK560f419e;rport [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=98A7EBD5F3D53E840A465B4642E740D9 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:40] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #91 [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Stopping retransmission on '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' of Request 103: Match Found [Sep 6 21:00:40] DEBUG[626] chan_sip.c: Destroying SIP dialog 469b66621d0364552cbe96aa5636c4ba@178.33.33.224 [Sep 6 21:00:40] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '469b66621d0364552cbe96aa5636c4ba@178.33.33.224' Method: INVITE [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 1 INVITE From: "222" ;tag=4a5864f3 To: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK322a660c75015e0cb0b83fcf1f8da67a363236 Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5077 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 55b723039bbe7f960cc21778cdd9c5cddb246900af51a7fa48e03628dc1e0a16 m=video 5079 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 6f21a1f9a1f007d91cae4f53f1e988a33fa70e8d2b19e26405822d404d11fb62 <-------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 1 INVITE [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=4a5864f3 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK322a660c75015e0cb0b83fcf1f8da67a363236 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 7 [ 86]: Contact: "222" [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 8 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 10 [ 19]: Content-Length: 741 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5077 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 55b723039bbe7f960cc21778cdd9c5cddb246900af51a7fa48e03628dc1e0a16 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5079 RTP/AVP 100 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 6f21a1f9a1f007d91cae4f53f1e988a33fa70e8d2b19e26405822d404d11fb62 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: --- (11 headers 24 lines) --- [Sep 6 21:00:43] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:43] VERBOSE[626] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 - INVITE (With RTP) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK322a660c75015e0cb0b83fcf1f8da67a363236;received=79.197.197.13 From: "222" ;tag=4a5864f3 To: ;tag=as44038de2 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 1 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6a13e5c0" Content-Length: 0 <------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #92 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog '4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0' in 6400 ms (Method: INVITE) [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@sipzone.tk SIP/2.0 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "222" ;tag=4a5864f3 To: ;tag=as44038de2 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK322a660c75015e0cb0b83fcf1f8da67a363236 CSeq: 1 ACK Content-Length: 0 <-------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 0 [ 30]: ACK sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=4a5864f3 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 4 [ 39]: To: ;tag=as44038de2 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK322a660c75015e0cb0b83fcf1f8da67a363236 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 6 [ 11]: CSeq: 1 ACK [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:43] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #92 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Stopping retransmission on '4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0' of Response 1: Match Found [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 2 INVITE From: "222" ;tag=4a5864f3 To: Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236 Authorization: Digest username="222",realm="asterisk",nonce="6a13e5c0",uri="sip:111@sipzone.tk",response="9802d7de1a74dd1b81810e7bf1cafd11",algorithm=MD5 Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5077 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 55b723039bbe7f960cc21778cdd9c5cddb246900af51a7fa48e03628dc1e0a16 m=video 5079 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 6f21a1f9a1f007d91cae4f53f1e988a33fa70e8d2b19e26405822d404d11fb62 <-------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 2 INVITE [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=4a5864f3 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 6 [ 86]: Contact: "222" [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 7 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 9 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 10 [153]: Authorization: Digest username="222",realm="asterisk",nonce="6a13e5c0",uri="sip:111@sipzone.tk",response="9802d7de1a74dd1b81810e7bf1cafd11",algorithm=MD5 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 11 [ 19]: Content-Length: 741 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5077 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 55b723039bbe7f960cc21778cdd9c5cddb246900af51a7fa48e03628dc1e0a16 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5079 RTP/AVP 100 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 6f21a1f9a1f007d91cae4f53f1e988a33fa70e8d2b19e26405822d404d11fb62 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: --- (12 headers 24 lines) --- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing session-level SDP o=222 0 0 IN IP4 192.168.178.103... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.178.103... OK. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 96 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 97 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 0 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 8 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 98 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 99 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 5 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 6 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 15 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP audio format 101 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 96 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 speex/32000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 97 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 speex/16000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format PCMU for ID 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format PCMA for ID 8 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format iLBC for ID 98 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:98 iLBC/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 99 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:99 speex/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 5 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:5 DVI4/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 6 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:6 DVI4/16000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format G728 for ID 15 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:15 G728/8000... OK. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found audio description format telephone-event for ID 101 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=zrtp-hash:1.10 55b723039bbe7f960cc21778cdd9c5cddb246900af51a7fa48e03628dc1e0a16... UNSUPPORTED. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found RTP video format 100 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=recvonly... UNSUPPORTED. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Found video description format H264 for ID 100 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=rtpmap:100 H264/90000... OK. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=fmtp:100 packetization-mode=1... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]]... UNSUPPORTED. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=zrtp-hash:1.10 6f21a1f9a1f007d91cae4f53f1e988a33fa70e8d2b19e26405822d404d11fb62... UNSUPPORTED. [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x62c (ulaw|alaw|adpcm|speex|ilbc)/video=0x200000 (h264)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Peer audio RTP is at port 192.168.178.103:5077 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Checking SIP call limits for device 222 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Updating call counter for incoming call [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: Looking for 111 in Sip-Out (domain sipzone.tk) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:43] DEBUG[626] chan_sip.c: build_route: Contact hop: "222" [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: list_route: hop: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: SIP/222-00000006: New call is still down.... Trying... [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236;received=79.197.197.13 From: "222" ;tag=4a5864f3 To: Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:43] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:43] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:43] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:43] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:43] DEBUG[739] pbx.c: Launching 'Set' [Sep 6 21:00:43] VERBOSE[739] pbx.c: -- Executing [111@Sip-Out:1] Set("SIP/222-00000006", "NR=111") in new stack [Sep 6 21:00:43] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:43] DEBUG[739] pbx.c: Launching 'Wait' [Sep 6 21:00:43] VERBOSE[739] pbx.c: -- Executing [111@Sip-Out:2] Wait("SIP/222-00000006", "100") in new stack [Sep 6 21:00:43] DEBUG[704] manager.c: Manager received command 'Redirect' [Sep 6 21:00:43] DEBUG[704] channel.c: Soft-Hanging up channel 'SIP/222-00000006' [Sep 6 21:00:43] DEBUG[739] pbx.c: Spawn extension (initCall,s,1) exited non-zero on 'SIP/222-00000006' [Sep 6 21:00:43] VERBOSE[739] pbx.c: == Spawn extension (initCall, s, 1) exited non-zero on 'SIP/222-00000006' [Sep 6 21:00:43] DEBUG[739] pbx.c: Launching 'Dial' [Sep 6 21:00:43] VERBOSE[739] pbx.c: -- Executing [s@initCall:1] Dial("SIP/222-00000006", "SIP/111,,M(Timeout)") in new stack [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Sep 6 21:00:43] VERBOSE[739] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Allocating new SIP dialog for 17bcb7f04032e84c5728f87f3dba990d@178.33.33.224 - INVITE (With RTP) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:43] DEBUG[739] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 6 21:00:43] DEBUG[739] acl.c: Found IP address for this socket [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable DIALEDTIME. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable ANSWEREDTIME. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable DIALEDPEERNAME. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable DIALEDPEERNUMBER. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable DIALSTATUS. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable NR. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable SIPCALLID. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable SIPDOMAIN. [Sep 6 21:00:43] DEBUG[739] channel.c: Not copying variable SIPURI. [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Outgoing Call for 111 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Updating call counter for outgoing call [Sep 6 21:00:43] DEBUG[739] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Sep 6 21:00:43] DEBUG[739] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: Audio is at 178.33.33.224 port 10180 [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 6 21:00:43] DEBUG[739] chan_sip.c: -- Done with adding codecs to SDP [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Initializing initreq for method INVITE - callid 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 0 [ 75]: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 3 [ 49]: From: "imox" ;tag=as4ed05bdd [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 4 [ 66]: To: [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 5 [ 30]: Contact: [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 6 [ 55]: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:43 GMT [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport Max-Forwards: 70 From: "imox" ;tag=as4ed05bdd To: Contact: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 288 v=0 o=root 709914351 709914351 IN IP4 178.33.33.224 s=Asterisk PBX 1.6.2.11 c=IN IP4 178.33.33.224 t=0 0 m=audio 10180 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 --- [Sep 6 21:00:43] DEBUG[739] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #95 [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:43] VERBOSE[739] app_dial.c: -- Called 111 [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 100 Trying From: "imox" ;tag=as4ed05bdd Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport To: Content-Length: 0 <-------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4ed05bdd [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 5 [ 66]: To: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 7 [ 0]: [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: --- (7 headers 0 lines) --- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: *** SIP TIMER: Cancelling retransmission #95 - INVITE (got response) [Sep 6 21:00:43] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224' Request 102: Found [Sep 6 21:00:43] DEBUG[626] chan_sip.c: SIP response 100 to standard invite [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 180 Ringing From: "imox" ;tag=as4ed05bdd Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport To: ;tag=D0D648DDA21DBF6853F633A364F4EF2E Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4ed05bdd [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=D0D648DDA21DBF6853F633A364F4EF2E [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:43] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:43] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:43] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224' Request 102: Found [Sep 6 21:00:43] DEBUG[626] chan_sip.c: SIP response 180 to standard invite [Sep 6 21:00:43] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:43] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:43] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:43] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:43] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:43] VERBOSE[739] app_dial.c: -- SIP/111-00000007 is ringing [Sep 6 21:00:43] VERBOSE[739] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236;received=79.197.197.13 From: "222" ;tag=4a5864f3 To: ;tag=as45eb6877 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:43] DEBUG[739] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 486 Busy Here From: "imox" ;tag=as4ed05bdd Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport To: ;tag=D0D648DDA21DBF6853F633A364F4EF2E Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 0 [ 21]: SIP/2.0 486 Busy Here [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as4ed05bdd [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=D0D648DDA21DBF6853F633A364F4EF2E [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Acked pending invite 102 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Stopping retransmission on '01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 79.197.197.13 [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: Transmitting (NAT) to 79.197.197.13:41830: ACK sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK10a4e7fd;rport Max-Forwards: 70 From: "imox" ;tag=as4ed05bdd To: ;tag=D0D648DDA21DBF6853F633A364F4EF2E Contact: Call-ID: 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.11 Content-Length: 0 --- [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Trying to put 'ACK sip:111' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Setting SIP_ALREADYGONE on dialog 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:45] VERBOSE[739] app_dial.c: -- SIP/111-00000007 is busy [Sep 6 21:00:45] DEBUG[739] channel.c: Hanging up channel 'SIP/111-00000007' [Sep 6 21:00:45] DEBUG[739] chan_sip.c: Hangup call SIP/111-00000007, SIP callid 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:45] VERBOSE[739] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [Sep 6 21:00:45] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:45] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:45] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:45] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:45] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:45] DEBUG[739] rtp.c: Channel '' has no RTP, not doing anything [Sep 6 21:00:45] DEBUG[739] app_dial.c: Exiting with DIALSTATUS=BUSY. [Sep 6 21:00:45] VERBOSE[739] pbx.c: -- Auto fallthrough, channel 'SIP/222-00000006' status is 'BUSY' [Sep 6 21:00:45] VERBOSE[739] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236;received=79.197.197.13 From: "222" ;tag=4a5864f3 To: ;tag=as45eb6877 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer X-Asterisk-HangupCause: User busy X-Asterisk-HangupCauseCode: 17 Content-Length: 0 <------------> [Sep 6 21:00:45] DEBUG[739] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #98 [Sep 6 21:00:45] DEBUG[739] chan_sip.c: Trying to put 'SIP/2.0 486' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:45] DEBUG[739] chan_sip.c: Setting SIP_ALREADYGONE on dialog 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:45] DEBUG[739] channel.c: Soft-Hanging up channel 'SIP/222-00000006' [Sep 6 21:00:45] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:45] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:45] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:45] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:45] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:45] DEBUG[739] channel.c: Soft-Hanging up channel 'SIP/222-00000006' [Sep 6 21:00:45] DEBUG[739] channel.c: Hanging up channel 'SIP/222-00000006' [Sep 6 21:00:45] DEBUG[739] chan_sip.c: Hangup call SIP/222-00000006, SIP callid 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:45] DEBUG[739] cdr_addon_mysql.c: Inserting a CDR record. [Sep 6 21:00:45] DEBUG[739] cdr_addon_mysql.c: SQL command as follows: INSERT INTO tbl_cdrs (calldate,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2010-09-06 21:00:43','2','111','Sip-Out','SIP/222-00000006','SIP/111-00000007','Dial','SIP/111,,M(Timeout)','2','0','BUSY','3','222','1283799643.6') [Sep 6 21:00:45] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:45] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:45] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:45] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:45] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@sipzone.tk SIP/2.0 Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "222" ;tag=4a5864f3 To: ;tag=as45eb6877 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236 CSeq: 2 ACK Content-Length: 0 <-------------> [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 0 [ 30]: ACK sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=4a5864f3 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 4 [ 39]: To: ;tag=as45eb6877 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK53ac28d25c3fab2d09f5d27db4caecdb363236 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 6 [ 11]: CSeq: 2 ACK [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:45] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:45] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #98 [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Stopping retransmission on '4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0' of Response 2: Match Found [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Destroying SIP dialog 4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0 [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '4b6bbecd41d92c78937d5ac9c541e45d@0:0:0:0:0:0:0:0' Method: ACK [Sep 6 21:00:45] DEBUG[626] chan_sip.c: Destroying SIP dialog 01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224 [Sep 6 21:00:45] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '01bf68fb72ce386b1b0d3f933f25f93f@178.33.33.224' Method: INVITE [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> REGISTER sip:sipzone.tk SIP/2.0 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 96 REGISTER From: "222" ;tag=7facec3d To: "222" Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK88e59f2e39ee1100396e5445b4de6dce363236 Max-Forwards: 70 Authorization: Digest username="222",realm="asterisk",nonce="46409ea5",uri="sip:sipzone.tk",response="cb84a15f67723feaef5f8356f5887081",algorithm=MD5 User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Expires: 3600 Contact: "222" ;expires=3600 Content-Length: 0 <-------------> [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 2 [ 17]: CSeq: 96 REGISTER [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=7facec3d [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 4 [ 30]: To: "222" [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK88e59f2e39ee1100396e5445b4de6dce363236 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 7 [149]: Authorization: Digest username="222",realm="asterisk",nonce="46409ea5",uri="sip:sipzone.tk",response="cb84a15f67723feaef5f8356f5887081",algorithm=MD5 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 8 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 9 [ 13]: Expires: 3600 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 10 [ 99]: Contact: "222" ;expires=3600 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: --- (12 headers 0 lines) --- [Sep 6 21:00:46] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:46] NOTICE[626] chan_sip.c: Correct auth, but based on stale nonce received from '"222" ;tag=7facec3d' [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK88e59f2e39ee1100396e5445b4de6dce363236;received=79.197.197.13 From: "222" ;tag=7facec3d To: "222" ;tag=as30710082 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 96 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="304b51c0", stale=true Content-Length: 0 <------------> [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0' in 32000 ms (Method: REGISTER) [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> REGISTER sip:sipzone.tk SIP/2.0 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 97 REGISTER From: "222" ;tag=7facec3d To: "222" Max-Forwards: 70 User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Expires: 3600 Contact: "222" ;expires=3600 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc82196d4f67225e8810a537cbdbf5075363236 Authorization: Digest username="222",realm="asterisk",nonce="304b51c0",uri="sip:sipzone.tk",response="769da51c573ac078ee55bf576e1c65ae",algorithm=MD5 Content-Length: 0 <-------------> [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 0 [ 31]: REGISTER sip:sipzone.tk SIP/2.0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 2 [ 17]: CSeq: 97 REGISTER [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=7facec3d [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 4 [ 30]: To: "222" [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 6 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 7 [ 13]: Expires: 3600 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 8 [ 99]: Contact: "222" ;expires=3600 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 9 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc82196d4f67225e8810a537cbdbf5075363236 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 10 [149]: Authorization: Digest username="222",realm="asterisk",nonce="304b51c0",uri="sip:sipzone.tk",response="769da51c573ac078ee55bf576e1c65ae",algorithm=MD5 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: --- (12 headers 0 lines) --- [Sep 6 21:00:46] DEBUG[626] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Initializing initreq for method REGISTER - callid aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 21b547be6a10a9267479d8802cd9a92c@178.33.33.224 - OPTIONS (No RTP) [Sep 6 21:00:46] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:46] DEBUG[626] config.c: extract inaddr from [178.33.33.224] gives [178.33.33.224:5060](0) [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Initializing initreq for method OPTIONS - callid 297dcfc7335694830307d2631459581d@178.33.33.224 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 0 [ 85]: OPTIONS sip:222@192.168.178.103:5060;transport=udp;registering_acc=sipzone_tk SIP/2.0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK18d36eee;rport [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as67a9d446 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 4 [ 75]: To: [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 5 [ 37]: Contact: [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 6 [ 55]: Call-ID: 297dcfc7335694830307d2631459581d@178.33.33.224 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:46 GMT [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:61299: OPTIONS sip:222@192.168.178.103:5060;transport=udp;registering_acc=sipzone_tk SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK18d36eee;rport Max-Forwards: 70 From: "asterisk" ;tag=as67a9d446 To: Contact: Call-ID: 297dcfc7335694830307d2631459581d@178.33.33.224 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:46 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 6 21:00:46] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #101 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bKc82196d4f67225e8810a537cbdbf5075363236;received=79.197.197.13 From: "222" ;tag=7facec3d To: "222" ;tag=as30710082 Call-ID: aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0 CSeq: 97 REGISTER Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 3600 Contact: ;expires=3600 Date: Mon, 06 Sep 2010 19:00:46 GMT Content-Length: 0 <------------> [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:46] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog 'aaab42e9c4ea1ddc2f90e430c1606dcc@0:0:0:0:0:0:0:0' in 32000 ms (Method: REGISTER) [Sep 6 21:00:46] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:46] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:46] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:46] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> SIP/2.0 200 OK To: ;tag=6886e9a0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK18d36eee;rport=5060;received=178.33.33.224 CSeq: 102 OPTIONS Call-ID: 297dcfc7335694830307d2631459581d@178.33.33.224 From: "asterisk" ;tag=as67a9d446 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE Allow-Events: refer Content-Length: 0 <-------------> [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 1 [ 88]: To: ;tag=6886e9a0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 2 [ 92]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK18d36eee;rport=5060;received=178.33.33.224 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 3 [ 17]: CSeq: 102 OPTIONS [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 4 [ 55]: Call-ID: 297dcfc7335694830307d2631459581d@178.33.33.224 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 5 [ 60]: From: "asterisk" ;tag=as67a9d446 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 6 [ 86]: Contact: "222" [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 7 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 8 [ 80]: Allow: INFO,OPTIONS,MESSAGE,BYE,REFER,SUBSCRIBE,ACK,CANCEL,PUBLISH,NOTIFY,INVITE [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 9 [ 19]: Allow-Events: refer [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: --- (11 headers 0 lines) --- [Sep 6 21:00:46] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #101 [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Stopping retransmission on '297dcfc7335694830307d2631459581d@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:46] DEBUG[626] chan_sip.c: Destroying SIP dialog 297dcfc7335694830307d2631459581d@178.33.33.224 [Sep 6 21:00:46] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '297dcfc7335694830307d2631459581d@178.33.33.224' Method: OPTIONS [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 1 INVITE From: "222" ;tag=82663a41 To: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK52c1ea4c13995ca7fb692b346ae17d88363236 Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5081 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 0f56752e9233e0bf2ef00592ffb120a5409ce372c3778090421eca0bdac62f77 m=video 5083 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 97e4b4bffba5ccd54d90323e6ba6aa37c6824cee1a1b94a41b9908f1eeefe923 <-------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 1 INVITE [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=82663a41 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK52c1ea4c13995ca7fb692b346ae17d88363236 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 7 [ 86]: Contact: "222" [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 8 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 10 [ 19]: Content-Length: 741 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 11 [ 0]: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5081 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 0f56752e9233e0bf2ef00592ffb120a5409ce372c3778090421eca0bdac62f77 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5083 RTP/AVP 100 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 97e4b4bffba5ccd54d90323e6ba6aa37c6824cee1a1b94a41b9908f1eeefe923 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: --- (11 headers 24 lines) --- [Sep 6 21:00:49] DEBUG[626] acl.c: Found IP address for this socket [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:49] VERBOSE[626] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Allocating new SIP dialog for 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 - INVITE (With RTP) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK52c1ea4c13995ca7fb692b346ae17d88363236;received=79.197.197.13 From: "222" ;tag=82663a41 To: ;tag=as7df941c0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 1 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2fa5ad09" Content-Length: 0 <------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #105 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Scheduling destruction of SIP dialog '255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0' in 6400 ms (Method: INVITE) [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@sipzone.tk SIP/2.0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "222" ;tag=82663a41 To: ;tag=as7df941c0 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK52c1ea4c13995ca7fb692b346ae17d88363236 CSeq: 1 ACK Content-Length: 0 <-------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 0 [ 30]: ACK sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=82663a41 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 4 [ 39]: To: ;tag=as7df941c0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK52c1ea4c13995ca7fb692b346ae17d88363236 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 6 [ 11]: CSeq: 1 ACK [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:49] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #105 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Stopping retransmission on '255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0' of Response 1: Match Found [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> INVITE sip:111@sipzone.tk SIP/2.0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 2 INVITE From: "222" ;tag=82663a41 To: Max-Forwards: 70 Contact: "222" User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X Content-Type: application/sdp Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 Authorization: Digest username="222",realm="asterisk",nonce="2fa5ad09",uri="sip:111@sipzone.tk",response="d4b8a559e037d59851cad02ffeed7eb6",algorithm=MD5 Content-Length: 741 v=0 o=222 0 0 IN IP4 192.168.178.103 s=- c=IN IP4 192.168.178.103 t=0 0 m=audio 5081 RTP/AVP 96 97 0 8 98 99 5 6 15 101 a=rtpmap:96 speex/32000 a=rtpmap:97 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:98 iLBC/8000 a=rtpmap:99 speex/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:6 DVI4/16000 a=rtpmap:15 G728/8000 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=zrtp-hash:1.10 0f56752e9233e0bf2ef00592ffb120a5409ce372c3778090421eca0bdac62f77 m=video 5083 RTP/AVP 100 a=recvonly a=rtpmap:100 H264/90000 a=fmtp:100 packetization-mode=1 a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] a=zrtp-hash:1.10 97e4b4bffba5ccd54d90323e6ba6aa37c6824cee1a1b94a41b9908f1eeefe923 <-------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 0 [ 33]: INVITE sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 2 [ 14]: CSeq: 2 INVITE [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=82663a41 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 4 [ 24]: To: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 5 [ 16]: Max-Forwards: 70 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 6 [ 86]: Contact: "222" [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 7 [ 65]: User-Agent: SIP Communicator1.0-alpha6-nightly.build.2915Mac OS X [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 9 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 10 [153]: Authorization: Digest username="222",realm="asterisk",nonce="2fa5ad09",uri="sip:111@sipzone.tk",response="d4b8a559e037d59851cad02ffeed7eb6",algorithm=MD5 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 11 [ 19]: Content-Length: 741 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 12 [ 0]: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 0 [ 3]: v=0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 1 [ 32]: o=222 0 0 IN IP4 192.168.178.103 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 2 [ 3]: s=- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 3 [ 24]: c=IN IP4 192.168.178.103 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 5 [ 47]: m=audio 5081 RTP/AVP 96 97 0 8 98 99 5 6 15 101 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 6 [ 23]: a=rtpmap:96 speex/32000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 7 [ 23]: a=rtpmap:97 speex/16000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 10 [ 21]: a=rtpmap:98 iLBC/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 11 [ 22]: a=rtpmap:99 speex/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 13 [ 21]: a=rtpmap:6 DVI4/16000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 14 [ 21]: a=rtpmap:15 G728/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 16 [ 54]: a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 17 [ 81]: a=zrtp-hash:1.10 0f56752e9233e0bf2ef00592ffb120a5409ce372c3778090421eca0bdac62f77 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 18 [ 24]: m=video 5083 RTP/AVP 100 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 19 [ 10]: a=recvonly [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 20 [ 23]: a=rtpmap:100 H264/90000 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 21 [ 31]: a=fmtp:100 packetization-mode=1 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 22 [ 51]: a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]] [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Body 23 [ 81]: a=zrtp-hash:1.10 97e4b4bffba5ccd54d90323e6ba6aa37c6824cee1a1b94a41b9908f1eeefe923 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: --- (12 headers 24 lines) --- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Initializing initreq for method INVITE - callid 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Using INVITE request as basis request - 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found peer '222' for '222' from 79.197.197.13:61299 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing session-level SDP o=222 0 0 IN IP4 192.168.178.103... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.178.103... OK. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 96 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 97 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 0 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 8 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 98 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 99 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 5 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 6 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 15 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP audio format 101 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 96 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 speex/32000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 97 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 speex/16000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format PCMU for ID 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format PCMA for ID 8 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format iLBC for ID 98 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:98 iLBC/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format speex for ID 99 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:99 speex/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 5 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:5 DVI4/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format DVI4 for ID 6 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:6 DVI4/16000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format G728 for ID 15 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:15 G728/8000... OK. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found audio description format telephone-event for ID 101 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (audio) SDP a=zrtp-hash:1.10 0f56752e9233e0bf2ef00592ffb120a5409ce372c3778090421eca0bdac62f77... UNSUPPORTED. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found RTP video format 100 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=recvonly... UNSUPPORTED. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Found video description format H264 for ID 100 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=rtpmap:100 H264/90000... OK. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=fmtp:100 packetization-mode=1... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=imageattr:100 send * recv [x=[0-1920],y=[0-1200]]... UNSUPPORTED. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Processing media-level (video) SDP a=zrtp-hash:1.10 97e4b4bffba5ccd54d90323e6ba6aa37c6824cee1a1b94a41b9908f1eeefe923... UNSUPPORTED. [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x62c (ulaw|alaw|adpcm|speex|ilbc)/video=0x200000 (h264)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Peer audio RTP is at port 192.168.178.103:5081 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Checking SIP call limits for device 222 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Updating call counter for incoming call [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: Looking for 111 in Sip-Out (domain sipzone.tk) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:49] DEBUG[626] chan_sip.c: build_route: Contact hop: "222" [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: list_route: hop: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: SIP/222-00000008: New call is still down.... Trying... [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236;received=79.197.197.13 From: "222" ;tag=82663a41 To: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:49] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:49] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:49] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:49] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:49] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:49] DEBUG[740] pbx.c: Launching 'Set' [Sep 6 21:00:49] VERBOSE[740] pbx.c: -- Executing [111@Sip-Out:1] Set("SIP/222-00000008", "NR=111") in new stack [Sep 6 21:00:49] DEBUG[740] pbx.c: Launching 'Wait' [Sep 6 21:00:49] VERBOSE[740] pbx.c: -- Executing [111@Sip-Out:2] Wait("SIP/222-00000008", "100") in new stack [Sep 6 21:00:49] DEBUG[704] manager.c: Manager received command 'Redirect' [Sep 6 21:00:49] DEBUG[704] channel.c: Soft-Hanging up channel 'SIP/222-00000008' [Sep 6 21:00:49] DEBUG[740] pbx.c: Spawn extension (initCall,s,1) exited non-zero on 'SIP/222-00000008' [Sep 6 21:00:49] VERBOSE[740] pbx.c: == Spawn extension (initCall, s, 1) exited non-zero on 'SIP/222-00000008' [Sep 6 21:00:49] DEBUG[740] pbx.c: Launching 'Dial' [Sep 6 21:00:49] VERBOSE[740] pbx.c: -- Executing [s@initCall:1] Dial("SIP/222-00000008", "SIP/111,,M(Timeout)") in new stack [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Sep 6 21:00:49] VERBOSE[740] netsock.c: == Using SIP RTP CoS mark 5 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Allocating new SIP dialog for 61da4b4767a7a6705bc0bd9a1f044f67@178.33.33.224 - INVITE (With RTP) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Setting NAT on RTP to On [Sep 6 21:00:49] DEBUG[740] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 6 21:00:49] DEBUG[740] acl.c: Found IP address for this socket [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Target address 79.197.197.13 is not local, substituting externip [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 178.33.33.224:5060 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: This channel will not be able to handle video. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable DIALEDTIME. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable ANSWEREDTIME. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable DIALEDPEERNAME. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable DIALEDPEERNUMBER. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable DIALSTATUS. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable NR. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable SIPCALLID. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable SIPDOMAIN. [Sep 6 21:00:49] DEBUG[740] channel.c: Not copying variable SIPURI. [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Outgoing Call for 111 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Updating call counter for outgoing call [Sep 6 21:00:49] DEBUG[740] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Sep 6 21:00:49] DEBUG[740] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: Audio is at 178.33.33.224 port 19932 [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 6 21:00:49] DEBUG[740] chan_sip.c: -- Done with adding codecs to SDP [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Initializing initreq for method INVITE - callid 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 0 [ 75]: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 3 [ 49]: From: "imox" ;tag=as45d73e00 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 4 [ 66]: To: [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 5 [ 30]: Contact: [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 6 [ 55]: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 9 [ 35]: Date: Mon, 06 Sep 2010 19:00:49 GMT [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: INVITE sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport Max-Forwards: 70 From: "imox" ;tag=as45d73e00 To: Contact: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.11 Date: Mon, 06 Sep 2010 19:00:49 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 286 v=0 o=root 46102215 46102215 IN IP4 178.33.33.224 s=Asterisk PBX 1.6.2.11 c=IN IP4 178.33.33.224 t=0 0 m=audio 19932 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 --- [Sep 6 21:00:49] DEBUG[740] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #108 [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:49] VERBOSE[740] app_dial.c: -- Called 111 [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 100 Trying From: "imox" ;tag=as45d73e00 Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport To: Content-Length: 0 <-------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as45d73e00 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 5 [ 66]: To: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 7 [ 0]: [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: --- (7 headers 0 lines) --- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: *** SIP TIMER: Cancelling retransmission #108 - INVITE (got response) [Sep 6 21:00:49] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' Request 102: Found [Sep 6 21:00:49] DEBUG[626] chan_sip.c: SIP response 100 to standard invite [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 180 Ringing From: "imox" ;tag=as45d73e00 Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport To: ;tag=FE876AFD2961147B922FDF2E30471C46 Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as45d73e00 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=FE876AFD2961147B922FDF2E30471C46 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:49] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:49] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:49] DEBUG[626] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' Request 102: Found [Sep 6 21:00:49] DEBUG[626] chan_sip.c: SIP response 180 to standard invite [Sep 6 21:00:49] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:49] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:49] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:49] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:49] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:49] VERBOSE[740] app_dial.c: -- SIP/111-00000009 is ringing [Sep 6 21:00:49] VERBOSE[740] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236;received=79.197.197.13 From: "222" ;tag=82663a41 To: ;tag=as04798464 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [Sep 6 21:00:49] DEBUG[740] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> CANCEL sip:111@sipzone.tk SIP/2.0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 To: CSeq: 2 CANCEL From: "222" ;tag=82663a41 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 Max-Forwards: 70 Content-Length: 0 <-------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 0 [ 33]: CANCEL sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 2 [ 24]: To: [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 3 [ 14]: CSeq: 2 CANCEL [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 4 [ 45]: From: "222" ;tag=82663a41 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:52] DEBUG[626] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: Sending to 79.197.197.13 : 61299 (NAT) [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Setting SIP_ALREADYGONE on dialog 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- Reliably Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236;received=79.197.197.13 From: "222" ;tag=82663a41 To: ;tag=as04798464 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #111 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 487' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- Transmitting (NAT) to 79.197.197.13:61299 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236;received=79.197.197.13 From: "222" ;tag=82663a41 To: ;tag=as04798464 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 CSeq: 2 CANCEL Server: Asterisk PBX 1.6.2.11 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 79.197.197.13:61299 [Sep 6 21:00:52] DEBUG[740] rtp.c: Channel '' has no RTP, not doing anything [Sep 6 21:00:52] DEBUG[740] channel.c: Hanging up channel 'SIP/111-00000009' [Sep 6 21:00:52] DEBUG[740] chan_sip.c: Hangup call SIP/111-00000009, SIP callid 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:52] DEBUG[740] chan_sip.c: Hanging up channel in state Ringing (not UP) [Sep 6 21:00:52] VERBOSE[740] chan_sip.c: Scheduling destruction of SIP dialog '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' in 6400 ms (Method: INVITE) [Sep 6 21:00:52] DEBUG[740] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' Request 102: Found [Sep 6 21:00:52] VERBOSE[740] chan_sip.c: Reliably Transmitting (NAT) to 79.197.197.13:41830: CANCEL sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport Max-Forwards: 70 From: "imox" ;tag=as45d73e00 To: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 CANCEL User-Agent: Asterisk PBX 1.6.2.11 Content-Length: 0 --- [Sep 6 21:00:52] DEBUG[740] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #113 [Sep 6 21:00:52] DEBUG[740] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:52] VERBOSE[740] chan_sip.c: Scheduling destruction of SIP dialog '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' in 6400 ms (Method: INVITE) [Sep 6 21:00:52] DEBUG[740] app_dial.c: Exiting with DIALSTATUS=CANCEL. [Sep 6 21:00:52] DEBUG[740] pbx.c: Spawn extension (initCall,s,1) exited non-zero on 'SIP/222-00000008' [Sep 6 21:00:52] VERBOSE[740] pbx.c: == Spawn extension (initCall, s, 1) exited non-zero on 'SIP/222-00000008' [Sep 6 21:00:52] DEBUG[740] channel.c: Soft-Hanging up channel 'SIP/222-00000008' [Sep 6 21:00:52] DEBUG[740] channel.c: Hanging up channel 'SIP/222-00000008' [Sep 6 21:00:52] DEBUG[740] chan_sip.c: Hangup call SIP/222-00000008, SIP callid 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:52] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Sep 6 21:00:52] DEBUG[598] chan_sip.c: Checking device state for peer 111 [Sep 6 21:00:52] DEBUG[598] devicestate.c: Changing state for SIP/111 - state 1 (Not in use) [Sep 6 21:00:52] DEBUG[598] devicestate.c: device 'SIP/111' state '1' [Sep 6 21:00:52] DEBUG[607] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:52] DEBUG[740] cdr_addon_mysql.c: Inserting a CDR record. [Sep 6 21:00:52] DEBUG[740] cdr_addon_mysql.c: SQL command as follows: INSERT INTO tbl_cdrs (calldate,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2010-09-06 21:00:49','2','s','initCall','SIP/222-00000008','SIP/111-00000009','Dial','SIP/111,,M(Timeout)','3','0','NO ANSWER','3','222','1283799649.8') [Sep 6 21:00:52] DEBUG[598] devicestate.c: No provider found, checking channel drivers for SIP - 222 [Sep 6 21:00:52] DEBUG[598] chan_sip.c: Checking device state for peer 222 [Sep 6 21:00:52] DEBUG[598] devicestate.c: Changing state for SIP/222 - state 1 (Not in use) [Sep 6 21:00:52] DEBUG[598] devicestate.c: device 'SIP/222' state '1' [Sep 6 21:00:52] DEBUG[607] app_queue.c: Device 'SIP/222' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:61299 ---> ACK sip:111@sipzone.tk SIP/2.0 Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "222" ;tag=82663a41 To: ;tag=as04798464 Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 CSeq: 2 ACK Content-Length: 0 <-------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 0 [ 30]: ACK sip:111@sipzone.tk SIP/2.0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 1 [ 57]: Call-ID: 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 3 [ 45]: From: "222" ;tag=82663a41 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 4 [ 39]: To: ;tag=as04798464 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 5 [ 90]: Via: SIP/2.0/UDP 192.168.178.103:5060;branch=z9hG4bK95d510c19be047c168341d180a2d5fe4363236 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 6 [ 11]: CSeq: 2 ACK [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 8 [ 0]: [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: --- (8 headers 0 lines) --- [Sep 6 21:00:52] DEBUG[626] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 6 21:00:52] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #111 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Stopping retransmission on '255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0' of Response 2: Match Found [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Destroying SIP dialog 255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '255e2c159a40b17af75f5b39a5922413@0:0:0:0:0:0:0:0' Method: ACK [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 487 Request Terminated From: "imox" ;tag=as45d73e00 Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 INVITE Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport To: ;tag=FE876AFD2961147B922FDF2E30471C46 Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 0 [ 30]: SIP/2.0 487 Request Terminated [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as45d73e00 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 INVITE [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 5 [103]: To: ;tag=FE876AFD2961147B922FDF2E30471C46 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Acked pending invite 102 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Stopping retransmission on '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:52] DEBUG[626] chan_sip.c: SIP response 487 to standard invite [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: Transmitting (NAT) to 79.197.197.13:41830: ACK sip:111@192.168.178.141:41830;rinstance=CBAD28D31E637891CF38 SIP/2.0 Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport Max-Forwards: 70 From: "imox" ;tag=as45d73e00 To: ;tag=FE876AFD2961147B922FDF2E30471C46 Contact: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.11 Content-Length: 0 --- [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Trying to put 'ACK sip:111' onto UDP socket destined for 79.197.197.13:41830 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Updating call counter for outgoing call [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Setting SIP_ALREADYGONE on dialog 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: <--- SIP read from UDP:79.197.197.13:41830 ---> SIP/2.0 200 OK From: "imox" ;tag=as45d73e00 Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 CSeq: 102 CANCEL Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport To: Contact: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE Supported: replaces Content-Length: 0 <-------------> [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 1 [ 49]: From: "imox" ;tag=as45d73e00 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 2 [ 55]: Call-ID: 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 3 [ 16]: CSeq: 102 CANCEL [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 4 [ 64]: Via: SIP/2.0/UDP 178.33.33.224:5060;branch=z9hG4bK2c520d05;rport [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 5 [ 66]: To: [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 6 [ 40]: Contact: [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 7 [ 40]: Allow: OPTIONS, INVITE, ACK, CANCEL, BYE [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 8 [ 19]: Supported: replaces [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Header 10 [ 0]: [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: --- (10 headers 0 lines) --- [Sep 6 21:00:52] DEBUG[626] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #113 [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Stopping retransmission on '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' of Request 102: Match Found [Sep 6 21:00:52] DEBUG[626] chan_sip.c: Destroying SIP dialog 74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224 [Sep 6 21:00:52] VERBOSE[626] chan_sip.c: Really destroying SIP dialog '74ab9f0b20ce24fb3c4e44563f4a6ed5@178.33.33.224' Method: INVITE