[Dec 23 12:05:06] Asterisk SVN-branch-12-r404531 built by root @ newtonr-laptop on a x86_64 running Linux on 2013-12-23 17:19:01 UTC [Dec 23 12:05:06] DEBUG[22994] config.c: Parsing /etc/asterisk/logger.conf [Dec 23 12:05:06] VERBOSE[22994] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Dec 23 12:05:06] VERBOSE[22994] logger.c: Asterisk Queue Logger restarted [Dec 23 12:05:06] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=5817 (tdta0x7fb228025fb0) created. [Dec 23 12:05:06] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:06] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:06] DEBUG[22942] pjsip: tsx0x7fb228006 .Transaction created for Request msg OPTIONS/cseq=5817 (tdta0x7fb228025fb0) [Dec 23 12:05:06] DEBUG[22942] pjsip: tsx0x7fb228006 Sending Request msg OPTIONS/cseq=5817 (tdta0x7fb228025fb0) in state Null [Dec 23 12:05:06] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:06] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (432 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj14fbdd70-c586-40b1-af57-b19690c9febf ˙From: ;tag=98489b7e-ff23-4b3f-960c-2dad728d9c8f ˙To: ˙Contact: ˙Call-ID: f5c27a1e-4dfc-45ca-833c-7fe596272e06 ˙CSeq: 5817 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:06] DEBUG[22942] pjsip: tsx0x7fb228006 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:06] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=5817 (rdata0x7fb1fc003e58) [Dec 23 12:05:06] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (560 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj14fbdd70-c586-40b1-af57-b19690c9febf ˙From: ;tag=98489b7e-ff23-4b3f-960c-2dad728d9c8f ˙To: ˙Call-ID: f5c27a1e-4dfc-45ca-833c-7fe596272e06 ˙CSeq: 5817 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:06] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:06] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:06] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:06] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=5817 (rdata0x7fb1fc007dc8) [Dec 23 12:05:06] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:06] DEBUG[22941] pjsip: tdta0x7fb1fc00 ..Destroying txdata Request msg OPTIONS/cseq=61042 (tdta0x7fb1fc005d80) [Dec 23 12:05:06] DEBUG[22942] pjsip: tsx0x7fb228006 .Incoming Response msg 200/OPTIONS/cseq=5817 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:06] DEBUG[22941] pjsip: tsx0x7fb228005 Transaction destroyed! [Dec 23 12:05:06] DEBUG[22942] pjsip: tsx0x7fb228006 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:06] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:06] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:11] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=42342 (tdta0x7fb228003f30) created. [Dec 23 12:05:11] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:11] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:11] DEBUG[22942] pjsip: tsx0x7fb228005 .Transaction created for Request msg OPTIONS/cseq=42342 (tdta0x7fb228003f30) [Dec 23 12:05:11] DEBUG[22942] pjsip: tsx0x7fb228005 Sending Request msg OPTIONS/cseq=42342 (tdta0x7fb228003f30) in state Null [Dec 23 12:05:11] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:11] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj38ed4ecc-8141-48de-9e76-759cbc4b1ff4 ˙From: ;tag=5456469a-c17b-43bd-96da-b54d40b2d475 ˙To: ˙Contact: ˙Call-ID: 2b9dc8da-cecd-43e8-9076-80f8100c7ba4 ˙CSeq: 42342 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:11] DEBUG[22942] pjsip: tsx0x7fb228005 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:11] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=42342 (rdata0x7fb1fc003e58) [Dec 23 12:05:11] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj38ed4ecc-8141-48de-9e76-759cbc4b1ff4 ˙From: ;tag=5456469a-c17b-43bd-96da-b54d40b2d475 ˙To: ˙Call-ID: 2b9dc8da-cecd-43e8-9076-80f8100c7ba4 ˙CSeq: 42342 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:11] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=42342 (rdata0x7fb1fc007dc8) [Dec 23 12:05:11] DEBUG[22942] pjsip: tsx0x7fb228005 .Incoming Response msg 200/OPTIONS/cseq=42342 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:11] DEBUG[22942] pjsip: tsx0x7fb228005 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:11] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:11] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:11] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:11] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:11] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:11] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:11] DEBUG[22941] pjsip: tdta0x7fb22802 ..Destroying txdata Request msg OPTIONS/cseq=5817 (tdta0x7fb228025fb0) [Dec 23 12:05:11] DEBUG[22941] pjsip: tsx0x7fb228006 Transaction destroyed! [Dec 23 12:05:16] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=42791 (tdta0x7fb228025fb0) created. [Dec 23 12:05:16] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:16] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:16] DEBUG[22942] pjsip: tsx0x7fb228006 .Transaction created for Request msg OPTIONS/cseq=42791 (tdta0x7fb228025fb0) [Dec 23 12:05:16] DEBUG[22942] pjsip: tsx0x7fb228006 Sending Request msg OPTIONS/cseq=42791 (tdta0x7fb228025fb0) in state Null [Dec 23 12:05:16] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:16] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj13894098-63b7-4b7d-96b3-89d761ea2a3f ˙From: ;tag=f2ae5107-0285-4b84-bba6-bd3a429144d1 ˙To: ˙Contact: ˙Call-ID: a2ac2fed-1e2f-4ac4-9124-be27cd4d360f ˙CSeq: 42791 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:16] DEBUG[22942] pjsip: tsx0x7fb228006 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:16] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:16] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:16] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:16] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:16] DEBUG[22941] pjsip: tdta0x7fb22800 ..Destroying txdata Request msg OPTIONS/cseq=42342 (tdta0x7fb228003f30) [Dec 23 12:05:16] DEBUG[22941] pjsip: tsx0x7fb228005 Transaction destroyed! [Dec 23 12:05:16] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=42791 (rdata0x7fb1fc003e58) [Dec 23 12:05:16] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj13894098-63b7-4b7d-96b3-89d761ea2a3f ˙From: ;tag=f2ae5107-0285-4b84-bba6-bd3a429144d1 ˙To: ˙Call-ID: a2ac2fed-1e2f-4ac4-9124-be27cd4d360f ˙CSeq: 42791 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:16] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=42791 (rdata0x7fb1fc007dc8) [Dec 23 12:05:16] DEBUG[22942] pjsip: tsx0x7fb228006 .Incoming Response msg 200/OPTIONS/cseq=42791 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:16] DEBUG[22942] pjsip: tsx0x7fb228006 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:16] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:16] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:21] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=32338 (tdta0x7fb228003f30) created. [Dec 23 12:05:21] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:21] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:21] DEBUG[22942] pjsip: tsx0x7fb228005 .Transaction created for Request msg OPTIONS/cseq=32338 (tdta0x7fb228003f30) [Dec 23 12:05:21] DEBUG[22942] pjsip: tsx0x7fb228005 Sending Request msg OPTIONS/cseq=32338 (tdta0x7fb228003f30) in state Null [Dec 23 12:05:21] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:21] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj358f8dc2-a607-4f8c-bb9a-52bc458aa6fa ˙From: ;tag=a2cfd7ab-3ee9-4f4a-90bd-f5c9a46913ed ˙To: ˙Contact: ˙Call-ID: 94552c2f-9156-4dcd-ad2c-029b23c02368 ˙CSeq: 32338 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:21] DEBUG[22942] pjsip: tsx0x7fb228005 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:21] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=32338 (rdata0x7fb1fc003e58) [Dec 23 12:05:21] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj358f8dc2-a607-4f8c-bb9a-52bc458aa6fa ˙From: ;tag=a2cfd7ab-3ee9-4f4a-90bd-f5c9a46913ed ˙To: ˙Call-ID: 94552c2f-9156-4dcd-ad2c-029b23c02368 ˙CSeq: 32338 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:21] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=32338 (rdata0x7fb1fc007dc8) [Dec 23 12:05:21] DEBUG[22942] pjsip: tsx0x7fb228005 .Incoming Response msg 200/OPTIONS/cseq=32338 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:21] DEBUG[22942] pjsip: tsx0x7fb228005 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:21] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:21] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:21] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:21] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:21] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:21] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:21] DEBUG[22941] pjsip: tdta0x7fb22802 ..Destroying txdata Request msg OPTIONS/cseq=42791 (tdta0x7fb228025fb0) [Dec 23 12:05:21] DEBUG[22941] pjsip: tsx0x7fb228006 Transaction destroyed! [Dec 23 12:05:25] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=39651 (rdata0x7fb1fc003e58) [Dec 23 12:05:25] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (550 bytes) from UDP:10.24.18.16:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjhIZ0pNvEjR0ZwuX8XIMMaG3sHM3qfBH- ˙Max-Forwards: 70 ˙From: "RustyONE" ;tag=tlpyW-cReH.d6-tbwEV0cRyPAU6a6f38 ˙To: "RustyONE" ˙Call-ID: uK.SCx-6Nl1CLtHt7KBATVVCjewCTxpO ˙CSeq: 39651 REGISTER ˙User-Agent: Digium D40 1_3_2_0_54993 ˙Contact: "RustyONE" ˙Expires: 300 ˙Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:25] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=39651 (rdata0x7fb1fc007dc8) [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.16' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.16' and port ''. [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.16:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.16:5060' did not match any identify section rules [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Dec 23 12:05:25] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=39651 (tdta0x7fb1fc005d80) created [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.16' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.16' and port ''. [Dec 23 12:05:25] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (536 bytes) to UDP:10.24.18.16:5060 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/UDP 10.24.18.16:5060;rport;received=10.24.18.16;branch=z9hG4bKPjhIZ0pNvEjR0ZwuX8XIMMaG3sHM3qfBH- ˙Call-ID: uK.SCx-6Nl1CLtHt7KBATVVCjewCTxpO ˙From: "RustyONE" ;tag=tlpyW-cReH.d6-tbwEV0cRyPAU6a6f38 ˙To: "RustyONE" ;tag=z9hG4bKPjhIZ0pNvEjR0ZwuX8XIMMaG3sHM3qfBH- ˙CSeq: 39651 REGISTER ˙WWW-Authenticate: Digest realm="asterisk",nonce="1387821925/d306ee698de328d63356b97d12104ee3",opaque="4210c63b425214c6",algorithm=md5,qop="auth" ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:25] DEBUG[22942] pjsip: tdta0x7fb1fc00 .Destroying txdata Response msg 401/REGISTER/cseq=39651 (tdta0x7fb1fc005d80) [Dec 23 12:05:25] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=39652 (rdata0x7fb1fc003e58) [Dec 23 12:05:25] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (842 bytes) from UDP:10.24.18.16:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjDJ0dV8z1PWoIjzjxGOfsIEMbDi4KVj2H ˙Max-Forwards: 70 ˙From: "RustyONE" ;tag=tlpyW-cReH.d6-tbwEV0cRyPAU6a6f38 ˙To: "RustyONE" ˙Call-ID: uK.SCx-6Nl1CLtHt7KBATVVCjewCTxpO ˙CSeq: 39652 REGISTER ˙User-Agent: Digium D40 1_3_2_0_54993 ˙Contact: "RustyONE" ˙Expires: 300 ˙Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS ˙Authorization: Digest username="6001", realm="asterisk", nonce="1387821925/d306ee698de328d63356b97d12104ee3", uri="sip:10.24.18.124:5060", response="865d147f94184551c59ed6d6c5c6add3", algorithm=md5, cnonce="tOH7nD.8KBdoB5vYN.Eb3ea2.NvqVxeE", opaque="4210c63b425214c6", qop=auth, nc=00000001 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:25] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=39652 (rdata0x7fb1fc008da8) [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.16' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.16' and port ''. [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.16:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.16:5060' did not match any identify section rules [Dec 23 12:05:25] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Dec 23 12:05:25] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=39652 (tdta0x7fb1fc005d80) created [Dec 23 12:05:25] DEBUG[22942] res_pjsip_authenticator_digest.c: Calculated nonce 1387821925/d306ee698de328d63356b97d12104ee3. Actual nonce is 1387821925/d306ee698de328d63356b97d12104ee3 [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:25] DEBUG[22942] netsock2.c: Splitting '10.24.18.16' into... [Dec 23 12:05:25] DEBUG[22942] netsock2.c: ...host '10.24.18.16' and port ''. [Dec 23 12:05:25] DEBUG[22942] pjsip: tdta0x7fb1fc00 .Destroying txdata Response msg 401/REGISTER/cseq=39652 (tdta0x7fb1fc005d80) [Dec 23 12:05:25] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:25] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:25] DEBUG[22942] res_pjsip_registrar.c: Refreshed contact 'sip:6001@10.24.18.16:5060;ob' on AOR '6001' with new expiration of 300 seconds [Dec 23 12:05:25] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:25] DEBUG[22942] pjsip: endpoint Response msg 200/REGISTER/cseq=39652 (tdta0x7fb228025fb0) created [Dec 23 12:05:25] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (469 bytes) to UDP:10.24.18.16:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.16:5060;rport;received=10.24.18.16;branch=z9hG4bKPjDJ0dV8z1PWoIjzjxGOfsIEMbDi4KVj2H ˙Call-ID: uK.SCx-6Nl1CLtHt7KBATVVCjewCTxpO ˙From: "RustyONE" ;tag=tlpyW-cReH.d6-tbwEV0cRyPAU6a6f38 ˙To: "RustyONE" ;tag=z9hG4bKPjDJ0dV8z1PWoIjzjxGOfsIEMbDi4KVj2H ˙CSeq: 39652 REGISTER ˙Date: Mon, 23 Dec 2013 18:05:25 GMT ˙Contact: ;expires=299 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:25] DEBUG[22942] pjsip: tdta0x7fb22802 Destroying txdata Response msg 200/REGISTER/cseq=39652 (tdta0x7fb228025fb0) [Dec 23 12:05:26] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=62631 (tdta0x7fb1fc005d80) created. [Dec 23 12:05:26] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:26] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:26] DEBUG[22942] pjsip: tsx0x7fb228006 .Transaction created for Request msg OPTIONS/cseq=62631 (tdta0x7fb1fc005d80) [Dec 23 12:05:26] DEBUG[22942] pjsip: tsx0x7fb228006 Sending Request msg OPTIONS/cseq=62631 (tdta0x7fb1fc005d80) in state Null [Dec 23 12:05:26] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:26] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj062be801-7b9b-44f7-9e9a-38532717e352 ˙From: ;tag=ab0e7628-adc2-4413-871b-3dd44003ed50 ˙To: ˙Contact: ˙Call-ID: e2b49ab6-69f1-4a2f-bd14-0fbcf3137d03 ˙CSeq: 62631 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:26] DEBUG[22942] pjsip: tsx0x7fb228006 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:26] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:26] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:26] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:26] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:26] DEBUG[22941] pjsip: tdta0x7fb22800 ..Destroying txdata Request msg OPTIONS/cseq=32338 (tdta0x7fb228003f30) [Dec 23 12:05:26] DEBUG[22941] pjsip: tsx0x7fb228005 Transaction destroyed! [Dec 23 12:05:26] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=62631 (rdata0x7fb1fc003e58) [Dec 23 12:05:26] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj062be801-7b9b-44f7-9e9a-38532717e352 ˙From: ;tag=ab0e7628-adc2-4413-871b-3dd44003ed50 ˙To: ˙Call-ID: e2b49ab6-69f1-4a2f-bd14-0fbcf3137d03 ˙CSeq: 62631 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:26] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=62631 (rdata0x7fb1fc007dc8) [Dec 23 12:05:26] DEBUG[22942] pjsip: tsx0x7fb228006 .Incoming Response msg 200/OPTIONS/cseq=62631 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:26] DEBUG[22942] pjsip: tsx0x7fb228006 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:26] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:26] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:29] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=11 (rdata0x7fb1fc003e58) [Dec 23 12:05:29] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (809 bytes) from UDP:10.24.18.180:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.180:5060;branch=z9hG4bK62d04f814E50613A ˙From: "6003" ;tag=7E80FAC8-BEE297C9 ˙To: ˙CSeq: 11 REGISTER ˙Call-ID: eecc549c-2fe224fd-95d490d6@10.24.18.180 ˙Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" ˙User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.2.0477 ˙Accept-Language: en ˙Authorization: Digest username="6003", realm="asterisk", nonce="1387821690/862f260fb3d14f91c269c9160ed50da2", qop=auth, cnonce="FF4GWSRj9cdFzU4", nc=00000002, opaque="50c623f06611613a", uri="sip:10.24.18.124:5060", response="15c58da5c8d8b3c717b070a0339b6f38", algorithm=MD5 ˙Max-Forwards: 70 ˙Expires: 300 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:29] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=11 (rdata0x7fb1fc008da8) [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.180' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.180' and port ''. [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.180:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.180:5060' did not match any identify section rules [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6003 [Dec 23 12:05:29] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=11 (tdta0x7fb228025fb0) created [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.180' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.180' and port ''. [Dec 23 12:05:29] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (487 bytes) to UDP:10.24.18.180:5060 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/UDP 10.24.18.180:5060;rport;received=10.24.18.180;branch=z9hG4bK62d04f814E50613A ˙Call-ID: eecc549c-2fe224fd-95d490d6@10.24.18.180 ˙From: "6003" ;tag=7E80FAC8-BEE297C9 ˙To: ;tag=z9hG4bK62d04f814E50613A ˙CSeq: 11 REGISTER ˙WWW-Authenticate: Digest realm="asterisk",nonce="1387821929/1a3bf5a2d59199884f949f52ef214ff8",opaque="2a6353b40473c136",stale=true,algorithm=md5,qop="auth" ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:29] DEBUG[22942] pjsip: tdta0x7fb22802 .Destroying txdata Response msg 401/REGISTER/cseq=11 (tdta0x7fb228025fb0) [Dec 23 12:05:29] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=12 (rdata0x7fb1fc003e58) [Dec 23 12:05:29] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (809 bytes) from UDP:10.24.18.180:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.180:5060;branch=z9hG4bK413d7fab4512B114 ˙From: "6003" ;tag=7E80FAC8-BEE297C9 ˙To: ˙CSeq: 12 REGISTER ˙Call-ID: eecc549c-2fe224fd-95d490d6@10.24.18.180 ˙Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" ˙User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.2.0477 ˙Accept-Language: en ˙Authorization: Digest username="6003", realm="asterisk", nonce="1387821929/1a3bf5a2d59199884f949f52ef214ff8", qop=auth, cnonce="oTbXoIZHxYDP+wk", nc=00000001, opaque="2a6353b40473c136", uri="sip:10.24.18.124:5060", response="ca9a21656b5e5b14732780aaf04f391e", algorithm=MD5 ˙Max-Forwards: 70 ˙Expires: 300 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:29] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=12 (rdata0x7fb1fc008da8) [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.180' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.180' and port ''. [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.180:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.180:5060' did not match any identify section rules [Dec 23 12:05:29] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6003 [Dec 23 12:05:29] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=12 (tdta0x7fb228025fb0) created [Dec 23 12:05:29] DEBUG[22942] res_pjsip_authenticator_digest.c: Calculated nonce 1387821929/1a3bf5a2d59199884f949f52ef214ff8. Actual nonce is 1387821929/1a3bf5a2d59199884f949f52ef214ff8 [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:29] DEBUG[22942] netsock2.c: Splitting '10.24.18.180' into... [Dec 23 12:05:29] DEBUG[22942] netsock2.c: ...host '10.24.18.180' and port ''. [Dec 23 12:05:29] DEBUG[22942] pjsip: tdta0x7fb22802 .Destroying txdata Response msg 401/REGISTER/cseq=12 (tdta0x7fb228025fb0) [Dec 23 12:05:29] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:29] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:29] DEBUG[22942] res_pjsip_registrar.c: Refreshed contact 'sip:6003@10.24.18.180:5060' on AOR '6003' with new expiration of 300 seconds [Dec 23 12:05:29] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:29] DEBUG[22942] pjsip: endpoint Response msg 200/REGISTER/cseq=12 (tdta0x7fb228003f30) created [Dec 23 12:05:29] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (407 bytes) to UDP:10.24.18.180:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.180:5060;rport;received=10.24.18.180;branch=z9hG4bK413d7fab4512B114 ˙Call-ID: eecc549c-2fe224fd-95d490d6@10.24.18.180 ˙From: "6003" ;tag=7E80FAC8-BEE297C9 ˙To: ;tag=z9hG4bK413d7fab4512B114 ˙CSeq: 12 REGISTER ˙Date: Mon, 23 Dec 2013 18:05:29 GMT ˙Contact: ;expires=299 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:29] DEBUG[22942] pjsip: tdta0x7fb22800 Destroying txdata Response msg 200/REGISTER/cseq=12 (tdta0x7fb228003f30) [Dec 23 12:05:30] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=5393 (rdata0x7fb1fc003e58) [Dec 23 12:05:30] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (551 bytes) from UDP:10.24.18.138:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.138:5060;rport;branch=z9hG4bKPjn15PbFjhavQdtbjZqrQC70u5Sau4lfLE ˙Max-Forwards: 70 ˙From: "RustyTWO" ;tag=7Pc3wPmdiiLv6wfYFdl3YXFdEH5hd7SR ˙To: "RustyTWO" ˙Call-ID: ILqYkgwNesfLZYIyS4eJ58rCj5q4MMQw ˙CSeq: 5393 REGISTER ˙User-Agent: Digium D40 1_3_2_0_54993 ˙Contact: "RustyTWO" ˙Expires: 300 ˙Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:30] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=5393 (rdata0x7fb1fc007dc8) [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.138' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.138' and port ''. [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.138:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.138:5060' did not match any identify section rules [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6002 [Dec 23 12:05:30] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=5393 (tdta0x7fb228003f30) created [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.138' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.138' and port ''. [Dec 23 12:05:30] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (537 bytes) to UDP:10.24.18.138:5060 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/UDP 10.24.18.138:5060;rport;received=10.24.18.138;branch=z9hG4bKPjn15PbFjhavQdtbjZqrQC70u5Sau4lfLE ˙Call-ID: ILqYkgwNesfLZYIyS4eJ58rCj5q4MMQw ˙From: "RustyTWO" ;tag=7Pc3wPmdiiLv6wfYFdl3YXFdEH5hd7SR ˙To: "RustyTWO" ;tag=z9hG4bKPjn15PbFjhavQdtbjZqrQC70u5Sau4lfLE ˙CSeq: 5393 REGISTER ˙WWW-Authenticate: Digest realm="asterisk",nonce="1387821930/e21868a759f1ce2b5d122b64014b1e50",opaque="6294ab291447ec6a",algorithm=md5,qop="auth" ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:30] DEBUG[22942] pjsip: tdta0x7fb22800 .Destroying txdata Response msg 401/REGISTER/cseq=5393 (tdta0x7fb228003f30) [Dec 23 12:05:30] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=5394 (rdata0x7fb1fc003e58) [Dec 23 12:05:30] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP request (843 bytes) from UDP:10.24.18.138:5060 ---> ˙REGISTER sip:10.24.18.124:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.138:5060;rport;branch=z9hG4bKPjxLxMhnkPF16lypGro6dFiolVVLkRnlJd ˙Max-Forwards: 70 ˙From: "RustyTWO" ;tag=7Pc3wPmdiiLv6wfYFdl3YXFdEH5hd7SR ˙To: "RustyTWO" ˙Call-ID: ILqYkgwNesfLZYIyS4eJ58rCj5q4MMQw ˙CSeq: 5394 REGISTER ˙User-Agent: Digium D40 1_3_2_0_54993 ˙Contact: "RustyTWO" ˙Expires: 300 ˙Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS ˙Authorization: Digest username="6002", realm="asterisk", nonce="1387821930/e21868a759f1ce2b5d122b64014b1e50", uri="sip:10.24.18.124:5060", response="b818c64a34a26400c7ebfdee5a42897c", algorithm=md5, cnonce="OPQRPDu7D9TSjc6xpLQj2CCdWStU6xm1", opaque="6294ab291447ec6a", qop=auth, nc=00000001 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:30] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=5394 (rdata0x7fb1fc008da8) [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.138' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.138' and port ''. [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: Source address 10.24.18.138:5060 does not match identify 'mytrunk_identify' [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_ip.c: '10.24.18.138:5060' did not match any identify section rules [Dec 23 12:05:30] DEBUG[22942] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6002 [Dec 23 12:05:30] DEBUG[22942] pjsip: endpoint .Response msg 401/REGISTER/cseq=5394 (tdta0x7fb228003f30) created [Dec 23 12:05:30] DEBUG[22942] res_pjsip_authenticator_digest.c: Calculated nonce 1387821930/e21868a759f1ce2b5d122b64014b1e50. Actual nonce is 1387821930/e21868a759f1ce2b5d122b64014b1e50 [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.124' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.124' and port ''. [Dec 23 12:05:30] DEBUG[22942] netsock2.c: Splitting '10.24.18.138' into... [Dec 23 12:05:30] DEBUG[22942] netsock2.c: ...host '10.24.18.138' and port ''. [Dec 23 12:05:30] DEBUG[22942] pjsip: tdta0x7fb22800 .Destroying txdata Response msg 401/REGISTER/cseq=5394 (tdta0x7fb228003f30) [Dec 23 12:05:30] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:30] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:30] DEBUG[22942] res_pjsip_registrar.c: Refreshed contact 'sip:6002@10.24.18.138:5060;ob' on AOR '6002' with new expiration of 300 seconds [Dec 23 12:05:30] DEBUG[22942] config.c: extract int from [5] in [0, 86400] gives [5](0) [Dec 23 12:05:30] DEBUG[22942] pjsip: endpoint Response msg 200/REGISTER/cseq=5394 (tdta0x7fb228025fb0) created [Dec 23 12:05:30] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP response (471 bytes) to UDP:10.24.18.138:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.138:5060;rport;received=10.24.18.138;branch=z9hG4bKPjxLxMhnkPF16lypGro6dFiolVVLkRnlJd ˙Call-ID: ILqYkgwNesfLZYIyS4eJ58rCj5q4MMQw ˙From: "RustyTWO" ;tag=7Pc3wPmdiiLv6wfYFdl3YXFdEH5hd7SR ˙To: "RustyTWO" ;tag=z9hG4bKPjxLxMhnkPF16lypGro6dFiolVVLkRnlJd ˙CSeq: 5394 REGISTER ˙Date: Mon, 23 Dec 2013 18:05:30 GMT ˙Contact: ;expires=299 ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:30] DEBUG[22942] pjsip: tdta0x7fb22802 Destroying txdata Response msg 200/REGISTER/cseq=5394 (tdta0x7fb228025fb0) [Dec 23 12:05:31] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=12014 (tdta0x7fb228003f30) created. [Dec 23 12:05:31] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:31] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:31] DEBUG[22942] pjsip: tsx0x7fb228005 .Transaction created for Request msg OPTIONS/cseq=12014 (tdta0x7fb228003f30) [Dec 23 12:05:31] DEBUG[22942] pjsip: tsx0x7fb228005 Sending Request msg OPTIONS/cseq=12014 (tdta0x7fb228003f30) in state Null [Dec 23 12:05:31] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:31] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPja9c73e17-de32-452a-b4ab-43d60d4390fe ˙From: ;tag=cc412239-5c40-46d9-a542-a230c224cba6 ˙To: ˙Contact: ˙Call-ID: 2394c0be-4786-423e-9459-849567e6c775 ˙CSeq: 12014 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:31] DEBUG[22942] pjsip: tsx0x7fb228005 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:31] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=12014 (rdata0x7fb1fc003e58) [Dec 23 12:05:31] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPja9c73e17-de32-452a-b4ab-43d60d4390fe ˙From: ;tag=cc412239-5c40-46d9-a542-a230c224cba6 ˙To: ˙Call-ID: 2394c0be-4786-423e-9459-849567e6c775 ˙CSeq: 12014 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:31] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=12014 (rdata0x7fb1fc007dc8) [Dec 23 12:05:31] DEBUG[22942] pjsip: tsx0x7fb228005 .Incoming Response msg 200/OPTIONS/cseq=12014 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:31] DEBUG[22942] pjsip: tsx0x7fb228005 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:31] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:31] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:31] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:31] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:31] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:31] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:31] DEBUG[22941] pjsip: tdta0x7fb1fc00 ..Destroying txdata Request msg OPTIONS/cseq=62631 (tdta0x7fb1fc005d80) [Dec 23 12:05:31] DEBUG[22941] pjsip: tsx0x7fb228006 Transaction destroyed! [Dec 23 12:05:36] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=50255 (tdta0x7fb1fc005d80) created. [Dec 23 12:05:36] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:36] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:36] DEBUG[22942] pjsip: tsx0x7fb228006 .Transaction created for Request msg OPTIONS/cseq=50255 (tdta0x7fb1fc005d80) [Dec 23 12:05:36] DEBUG[22942] pjsip: tsx0x7fb228006 Sending Request msg OPTIONS/cseq=50255 (tdta0x7fb1fc005d80) in state Null [Dec 23 12:05:36] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:36] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (433 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj63f114ac-32ed-4ef5-a65d-e2b76406ebb7 ˙From: ;tag=2d5db391-f794-476c-8610-e6762587b604 ˙To: ˙Contact: ˙Call-ID: f9c041d2-e62b-4dc9-83f0-45e2ba693216 ˙CSeq: 50255 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:36] DEBUG[22942] pjsip: tsx0x7fb228006 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:36] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=50255 (rdata0x7fb1fc003e58) [Dec 23 12:05:36] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (561 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj63f114ac-32ed-4ef5-a65d-e2b76406ebb7 ˙From: ;tag=2d5db391-f794-476c-8610-e6762587b604 ˙To: ˙Call-ID: f9c041d2-e62b-4dc9-83f0-45e2ba693216 ˙CSeq: 50255 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:36] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:36] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:36] DEBUG[22941] pjsip: tsx0x7fb228005 Timeout timer event [Dec 23 12:05:36] DEBUG[22941] pjsip: tsx0x7fb228005 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:36] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=50255 (rdata0x7fb1fc007dc8) [Dec 23 12:05:36] DEBUG[22941] pjsip: tdta0x7fb22800 ..Destroying txdata Request msg OPTIONS/cseq=12014 (tdta0x7fb228003f30) [Dec 23 12:05:36] DEBUG[22942] pjsip: tsx0x7fb228006 .Incoming Response msg 200/OPTIONS/cseq=50255 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:36] DEBUG[22941] pjsip: tsx0x7fb228005 Transaction destroyed! [Dec 23 12:05:36] DEBUG[22942] pjsip: tsx0x7fb228006 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:36] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:36] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:41] DEBUG[22942] pjsip: endpoint Request msg OPTIONS/cseq=9865 (tdta0x7fb228025fb0) created. [Dec 23 12:05:41] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:41] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:41] DEBUG[22942] pjsip: tsx0x7fb228005 .Transaction created for Request msg OPTIONS/cseq=9865 (tdta0x7fb228025fb0) [Dec 23 12:05:41] DEBUG[22942] pjsip: tsx0x7fb228005 Sending Request msg OPTIONS/cseq=9865 (tdta0x7fb228025fb0) in state Null [Dec 23 12:05:41] DEBUG[22942] pjsip: sip_resolve.c .Target '10.24.18.166:5060' type=Unspecified resolved to '10.24.18.166:5060' type=UDP (UDP transport) [Dec 23 12:05:41] VERBOSE[22942] res_pjsip_logger.c: <--- Transmitting SIP request (432 bytes) to UDP:10.24.18.166:5060 ---> ˙OPTIONS sip:6004@10.24.18.166:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj253f9b1d-97b3-4a10-bc93-84ed5dd23db8 ˙From: ;tag=62421d5d-0ac1-4d5a-97f8-d0b00f566410 ˙To: ˙Contact: ˙Call-ID: 5481df98-ef89-460c-aaea-c3f1a059c8f2 ˙CSeq: 9865 OPTIONS ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:41] DEBUG[22942] pjsip: tsx0x7fb228005 .State changed from Null to Calling, event=TX_MSG [Dec 23 12:05:41] DEBUG[22941] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=9865 (rdata0x7fb1fc003e58) [Dec 23 12:05:41] VERBOSE[22941] res_pjsip_logger.c: <--- Received SIP response (560 bytes) from UDP:10.24.18.166:5060 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj253f9b1d-97b3-4a10-bc93-84ed5dd23db8 ˙From: ;tag=62421d5d-0ac1-4d5a-97f8-d0b00f566410 ˙To: ˙Call-ID: 5481df98-ef89-460c-aaea-c3f1a059c8f2 ˙CSeq: 9865 OPTIONS ˙Contact: ˙Supported: 100rel, replaces, timer ˙Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE ˙Accept: application/sdp, message/sipfrag, application/dtmf-relay ˙Content-Length: 0 ˙ ˙ [Dec 23 12:05:41] DEBUG[22942] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=9865 (rdata0x7fb1fc007dc8) [Dec 23 12:05:41] DEBUG[22942] pjsip: tsx0x7fb228005 .Incoming Response msg 200/OPTIONS/cseq=9865 (rdata0x7fb1fc007dc8) in state Calling [Dec 23 12:05:41] DEBUG[22942] pjsip: tsx0x7fb228005 ..State changed from Calling to Completed, event=RX_MSG [Dec 23 12:05:41] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:41] DEBUG[22942] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Dec 23 12:05:41] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:41] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Completed to Terminated, event=TIMER [Dec 23 12:05:41] DEBUG[22941] pjsip: tsx0x7fb228006 Timeout timer event [Dec 23 12:05:41] DEBUG[22941] pjsip: tsx0x7fb228006 .State changed from Terminated to Destroyed, event=TIMER [Dec 23 12:05:41] DEBUG[22941] pjsip: tdta0x7fb1fc00 ..Destroying txdata Request msg OPTIONS/cseq=50255 (tdta0x7fb1fc005d80) [Dec 23 12:05:41] DEBUG[22941] pjsip: tsx0x7fb228006 Transaction destroyed! [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor 'ast_msg_queue' [Dec 23 12:05:42] VERBOSE[22994] asterisk.c: Asterisk cleanly ending (0). [Dec 23 12:05:42] VERBOSE[22994] asterisk.c: Executing last minute cleanups [Dec 23 12:05:42] VERBOSE[22994] res_musiconhold.c: == Destroying musiconhold processes [Dec 23 12:05:42] DEBUG[22994] res_musiconhold.c: Destroying MOH class 'default' [Dec 23 12:05:42] DEBUG[22939] taskprocessor.c: destroying taskprocessor '3e123b0a-df77-4697-9992-9316d1a32aa1' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'CallCompletionCancel' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'CallCompletionRequest' [Dec 23 12:05:42] DEBUG[22994] logger.c: Unregistered dynamic logger level 'CC' with index 16. [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor 'CCSS core' [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor '749c8afc-9569-4e1d-bc4f-b5305eb536d1' [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeList [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeInfo [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeDestroy [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeKick [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Ping [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Events [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Logoff [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Login [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Challenge [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Hangup [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Status [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Setvar [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Getvar [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action GetConfig [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action GetConfigJSON [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action UpdateConfig [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action CreateConfig [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ListCategories [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Redirect [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Atxfer [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Originate [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Command [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ExtensionState [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action PresenceState [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action AbsoluteTimeout [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action MailboxStatus [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action MailboxCount [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ListCommands [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action SendText [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action UserEvent [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action WaitEvent [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action CoreSettings [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action CoreStatus [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Reload [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action CoreShowChannels [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ModuleLoad [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ModuleCheck [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action AOCMessage [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Filter [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BlindTransfer [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function AMI_CLIENT [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor 'ace78fa3-02ae-4f0f-adbc-8b9ef336372c' [Dec 23 12:05:42] DEBUG[22994] tcptls.c: Stopped server :: AMI server [Dec 23 12:05:42] DEBUG[22994] tcptls.c: Stopped server :: AMI TLS server [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action LocalOptimizeAway [Dec 23 12:05:42] DEBUG[22994] channel.c: Unregistering channel type 'Local' [Dec 23 12:05:42] VERBOSE[22994] channel.c: == Unregistered channel type 'Local' [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor '6c36b069-3596-4419-8121-907eabe8165b' [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor '159e4678-d71b-4d3f-bb48-11962e03e309' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Answer' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'BackGround' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Busy' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Congestion' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'ExecIfTime' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Goto' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'GotoIf' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'GotoIfTime' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'ImportVar' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Hangup' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Incomplete' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'NoOp' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Proceeding' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Progress' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'RaiseException' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Ringing' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SayAlpha' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SayAlphaCase' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SayDigits' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SayNumber' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SayPhonetic' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Set' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'MSet' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'SetAMAFlags' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Wait' [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'WaitExten' [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action ShowDialPlan [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function EXCEPTION [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function TESTTIME [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeTechnologyList [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeTechnologySuspend [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action BridgeTechnologyUnsuspend [Dec 23 12:05:42] DEBUG[22994] bridge.c: Waiting for bridge manager thread to die. [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function FEATUREMAP [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function FEATURE [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action Bridge [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'Bridge' [Dec 23 12:05:42] DEBUG[22994] tcptls.c: Stopped server :: http server [Dec 23 12:05:42] DEBUG[22994] channel.c: Unregistering channel type 'Surrogate' [Dec 23 12:05:42] VERBOSE[22994] channel.c: == Unregistered channel type 'Surrogate' [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action DataGet [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function MESSAGE [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered custom function MESSAGE_DATA [Dec 23 12:05:42] VERBOSE[22994] pbx.c: == Unregistered application 'MessageSend' [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action MessageSend [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action DBGet [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action DBPut [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action DBDel [Dec 23 12:05:42] VERBOSE[22994] manager.c: == Manager unregistered action DBDelTree [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor 'Sorcery-control' [Dec 23 12:05:42] DEBUG[22994] threadpool.c: Destroying worker thread 5 [Dec 23 12:05:42] DEBUG[22994] taskprocessor.c: destroying taskprocessor 'Sorcery' [Dec 23 12:05:42] DEBUG[22994] asterisk.c: Asterisk ending (0).