[Aug 20 20:37:01] Asterisk SVN-branch-12-r421608 built by root @ newtonr-laptop on a x86_64 running Linux on 2014-08-21 00:21:32 UTC [Aug 20 20:37:01] DEBUG[25155] config.c: Parsing /etc/asterisk/logger.conf [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=101 (rdata0x7fde28003938) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP request (898 bytes) from UDP:192.168.1.245:5060 ---> INVITE sip:2000@192.168.1.187 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.245:5060;branch=z9hG4bK-6ac22a75 From: "6001" ;tag=6d9cbcf322115fc5o0 To: Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 101 INVITE Max-Forwards: 70 Contact: "6001" Expires: 240 User-Agent: Linksys/SPA942-5.2.8 Content-Length: 395 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: replaces Content-Type: application/sdp v=0 o=- 32157 32157 IN IP4 192.168.1.245 s=- c=IN IP4 192.168.1.245 t=0 0 m=audio 16474 RTP/AVP 0 8 2 4 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=101 (rdata0x7fde28006868) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Aug 20 20:37:06] DEBUG[25101] pjsip: endpoint .Response msg 401/INVITE/cseq=101 (tdta0x7fde58004140) created [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.187' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.187' and port ''. [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.245' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.245' and port ''. [Aug 20 20:37:06] VERBOSE[25101] res_pjsip_logger.c: <--- Transmitting SIP response (458 bytes) to UDP:192.168.1.245:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.245:5060;rport;received=192.168.1.245;branch=z9hG4bK-6ac22a75 Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 From: "6001" ;tag=6d9cbcf322115fc5o0 To: ;tag=z9hG4bK-6ac22a75 CSeq: 101 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1408585026/ac3a5c574831511378106a9d111f2809",opaque="4b8fec3c2c261fd5",algorithm=md5,qop="auth" Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: tdta0x7fde5800 .Destroying txdata Response msg 401/INVITE/cseq=101 (tdta0x7fde58004140) [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=101 (rdata0x7fde28003938) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP request (387 bytes) from UDP:192.168.1.245:5060 ---> ACK sip:2000@192.168.1.187 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.245:5060;branch=z9hG4bK-6ac22a75 From: "6001" ;tag=6d9cbcf322115fc5o0 To: ;tag=z9hG4bK-6ac22a75 Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 101 ACK Max-Forwards: 70 Contact: "6001" User-Agent: Linksys/SPA942-5.2.8 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=101 (rdata0x7fde28005888) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=102 (rdata0x7fde28003938) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP request (1158 bytes) from UDP:192.168.1.245:5060 ---> INVITE sip:2000@192.168.1.187 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.245:5060;branch=z9hG4bK-8c6165d5 From: "6001" ;tag=6d9cbcf322115fc5o0 To: Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 102 INVITE Max-Forwards: 70 Authorization: Digest username="6001",realm="asterisk",nonce="1408585026/ac3a5c574831511378106a9d111f2809",uri="sip:2000@192.168.1.187",algorithm=MD5,response="fd4303c855272c6b019647826ca45301",opaque="4b8fec3c2c261fd5",qop=auth,nc=00000001,cnonce="2c06002d" Contact: "6001" Expires: 240 User-Agent: Linksys/SPA942-5.2.8 Content-Length: 395 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: replaces Content-Type: application/sdp v=0 o=- 32157 32157 IN IP4 192.168.1.245 s=- c=IN IP4 192.168.1.245 t=0 0 m=audio 16474 RTP/AVP 0 8 2 4 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=102 (rdata0x7fde280060a8) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 20 20:37:06] DEBUG[25101] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 6001 [Aug 20 20:37:06] DEBUG[25101] pjsip: endpoint .Response msg 401/INVITE/cseq=102 (tdta0x7fde58004140) created [Aug 20 20:37:06] DEBUG[25101] res_pjsip_authenticator_digest.c: Calculated nonce 1408585026/ac3a5c574831511378106a9d111f2809. Actual nonce is 1408585026/ac3a5c574831511378106a9d111f2809 [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.187' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.187' and port ''. [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.245' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.245' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: tdta0x7fde5800 .Destroying txdata Response msg 401/INVITE/cseq=102 (tdta0x7fde58004140) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..Transaction created for Request msg INVITE/cseq=102 (rdata0x7fde280060a8) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 .Incoming Request msg INVITE/cseq=102 (rdata0x7fde280060a8) in state Null [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..State changed from Null to Trying, event=RX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Transaction tsx0x7fde58006718 state changed to Trying [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .UAS dialog created [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Module mod-invite added as dialog usage, data=0x7fde580076a8 [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ..Session count inc to 2 by mod-invite [Aug 20 20:37:06] DEBUG[25101] pjsip: inv0x7fde58005 .UAS invite session created for dialog dlg0x7fde580056c8 [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Module Session Module added as dialog usage, data=(nil) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ..Session count inc to 2 by Session Module [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.245' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.245' and port ''. [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] res_rtp_asterisk.c: Allocated port 11362 for RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 ICE session created, comp_cnt=2, role is Unknown agent [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.187' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.187' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 0 added: comp_id=1, type=host, foundation=Hc0a801bb, addr=192.168.1.187:11362, base=192.168.1.187:11362, prio=0x7effffff (2130706431) [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '10.24.251.42' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '10.24.251.42' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 1 added: comp_id=1, type=host, foundation=Ha18fb2a, addr=10.24.251.42:11362, base=10.24.251.42:11362, prio=0x7effffff (2130706431) [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '173.17.135.67' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '173.17.135.67' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 2 added: comp_id=1, type=srflx, foundation=Sad118743, addr=173.17.135.67:11362, base=192.168.1.187:11362, prio=0x64ffffff (1694498815) [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: RTP instance '0x7fde58012738' is setup and ready to go [Aug 20 20:37:06] DEBUG[25101] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.187' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.187' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 3 added: comp_id=2, type=host, foundation=Hc0a801bb, addr=192.168.1.187:11363, base=192.168.1.187:11363, prio=0x7efffffe (2130706430) [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '10.24.251.42' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '10.24.251.42' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 4 added: comp_id=2, type=host, foundation=Ha18fb2a, addr=10.24.251.42:11363, base=10.24.251.42:11363, prio=0x7efffffe (2130706430) [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '173.17.135.67' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '173.17.135.67' and port ''. [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Candidate 5 added: comp_id=2, type=srflx, foundation=Sad118743, addr=173.17.135.67:11363, base=192.168.1.187:11363, prio=0x64fffffe (1694498814) [Aug 20 20:37:06] DEBUG[25101] pjsip: icess0x7fde580 Destroying ICE session 0x7fde5801a998 [Aug 20 20:37:06] DEBUG[25101] pjsip: stuse0x7fde580 STUN session 0x7fde5801c9a8 destroy request, ref_cnt=4 [Aug 20 20:37:06] DEBUG[25101] pjsip: stuse0x7fde580 STUN session 0x7fde5801d598 destroy request, ref_cnt=3 [Aug 20 20:37:06] DEBUG[25101] pjsip: ice_session.c ICE session 0x7fde5801a998 destroyed [Aug 20 20:37:06] DEBUG[25101] pjsip: stun_session.c STUN session 0x7fde5801c9a8 destroyed [Aug 20 20:37:06] DEBUG[25101] pjsip: stun_session.c STUN session 0x7fde5801d598 destroyed [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 0 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 8 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 2 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 4 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 18 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 96 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 97 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 98 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 101 based on m type on 0x7fde688ad200 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 0 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 2 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 4 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 8 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 18 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 96 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 97 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 98 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 101 from 0x7fde688ad200 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] pjsip: endpoint .Response msg 100/INVITE/cseq=102 (tdta0x7fde280008e0) created [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Initial answer Response msg 100/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 20 20:37:06] DEBUG[25101] pjsip: inv0x7fde58005 .Sending Response msg 100/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ..Sending Response msg 100/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..Sending Response msg 100/INVITE/cseq=102 (tdta0x7fde280008e0) in state Trying [Aug 20 20:37:06] VERBOSE[25101] res_pjsip_logger.c: <--- Transmitting SIP response (284 bytes) to UDP:192.168.1.245:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.245:5060;rport;received=192.168.1.245;branch=z9hG4bK-8c6165d5 Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 From: "6001" ;tag=6d9cbcf322115fc5o0 To: CSeq: 102 INVITE Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ...State changed from Trying to Proceeding, event=TX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ....Transaction tsx0x7fde58006718 state changed to Proceeding [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fde58006718) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: There is no transaction involved in this state change [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is INCOMING [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Sending response [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fde58006718) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Proceeding [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is INCOMING [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is INVITE [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 Module NAT added as dialog usage, data=(nil) [Aug 20 20:37:06] DEBUG[25101] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/6001-00000000 [Aug 20 20:37:06] DEBUG[25157][C-00000000] pbx.c: Launching 'Answer' [Aug 20 20:37:06] DEBUG[25092] devicestate.c: No provider found, checking channel drivers for PJSIP - 6001 [Aug 20 20:37:06] DEBUG[25092] devicestate.c: Changing state for PJSIP/6001 - state 2 (In use) [Aug 20 20:37:06] DEBUG[25151] app_queue.c: Device 'PJSIP/6001' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 20 20:37:06] DEBUG[25101] pjsip: inv0x7fde58005 .SDP negotiation done, status=0 [Aug 20 20:37:06] DEBUG[25101] netsock2.c: Splitting '192.168.1.245' into... [Aug 20 20:37:06] DEBUG[25101] netsock2.c: ...host '192.168.1.245' and port ''. [Aug 20 20:37:06] DEBUG[25101] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 0 based on m type on 0x7fde688acc50 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Setting payload 101 based on m type on 0x7fde688acc50 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 0 from 0x7fde688acc50 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Copying payload 101 from 0x7fde688acc50 to 0x7fde58012878 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Aug 20 20:37:06] DEBUG[25101] pjsip: inv0x7fde58005 .Sending Response msg 200/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ..Sending Response msg 200/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..Sending Response msg 200/INVITE/cseq=102 (tdta0x7fde280008e0) in state Proceeding [Aug 20 20:37:06] VERBOSE[25101] res_pjsip_logger.c: <--- Transmitting SIP response (803 bytes) to UDP:192.168.1.245:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.245:5060;rport;received=192.168.1.245;branch=z9hG4bK-8c6165d5 Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 From: "6001" ;tag=6d9cbcf322115fc5o0 To: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef CSeq: 102 INVITE Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Supported: 100rel, timer, replaces, norefersub Content-Type: application/sdp Content-Length: 254 v=0 o=- 32157 32159 IN IP4 newtonr-laptop s=Asterisk c=IN IP4 192.168.1.187 t=0 0 m=audio 11362 RTP/AVP 0 101 c=IN IP4 192.168.1.187 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ...State changed from Proceeding to Completed, event=TX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ....Transaction tsx0x7fde58006718 state changed to Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fde58006718) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: There is no transaction involved in this state change [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONNECTING [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Source of transaction state change is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Sending response [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fde58006718) [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONNECTING [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=102 (rdata0x7fde280038c8) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP request (667 bytes) from UDP:192.168.1.245:5060 ---> ACK sip:192.168.1.187:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.245:5060;branch=z9hG4bK-cb50fc56 From: "6001" ;tag=6d9cbcf322115fc5o0 To: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 102 ACK Max-Forwards: 70 Authorization: Digest username="6001",realm="asterisk",nonce="1408585026/ac3a5c574831511378106a9d111f2809",uri="sip:2000@192.168.1.187",algorithm=MD5,response="fd4303c855272c6b019647826ca45301",opaque="4b8fec3c2c261fd5",qop=auth,nc=00000001,cnonce="2c06002d" Contact: "6001" User-Agent: Linksys/SPA942-5.2.8 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=102 (rdata0x7fde280060a8) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Received Request msg ACK/cseq=102 (rdata0x7fde280060a8) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..Request to terminate transaction [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ...State changed from Completed to Terminated, event=USER [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ....Transaction tsx0x7fde58006718 state changed to Terminated [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Terminated [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is USER [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONNECTING [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: There is no transaction involved in this state change [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Received request [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is ACK [Aug 20 20:37:06] DEBUG[25106] pjsip: tsx0x7fde58006 Timeout timer event [Aug 20 20:37:06] DEBUG[25106] pjsip: tsx0x7fde58006 .State changed from Terminated to Destroyed, event=TIMER [Aug 20 20:37:06] DEBUG[25106] pjsip: tdta0x7fde2800 ..Destroying txdata Response msg 200/INVITE/cseq=102 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25106] pjsip: tsx0x7fde58006 Transaction destroyed! [Aug 20 20:37:06] DEBUG[25157][C-00000000] res_rtp_asterisk.c: 0x7fde58017d40 -- Probation learning mode pass with source address 192.168.1.245:16474 [Aug 20 20:37:06] DEBUG[25157][C-00000000] pbx.c: Launching 'Transfer' [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 Module mod-evsub added as dialog usage, data=0x7fde580112a8 [Aug 20 20:37:06] DEBUG[25101] pjsip: evsub0x7fde580 UAC subscription created, using dialog dlg0x7fde580056c8 [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Session count inc to 5 by mod-evsub [Aug 20 20:37:06] DEBUG[25101] pjsip: endpoint Request msg REFER/cseq=16171 (tdta0x7fde280008e0) created. [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .Sending Request msg REFER/cseq=16171 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..Transaction created for Request msg REFER/cseq=16170 (tdta0x7fde280008e0) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 .Sending Request msg REFER/cseq=16170 (tdta0x7fde280008e0) in state Null [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_resolve.c ..Target '192.168.1.245:5060' type=Unspecified resolved to '192.168.1.245:5060' type=UDP (UDP transport) [Aug 20 20:37:06] VERBOSE[25101] res_pjsip_logger.c: <--- Transmitting SIP request (575 bytes) to UDP:192.168.1.245:5060 ---> REFER sip:6001@192.168.1.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.187:5060;rport;branch=z9hG4bKPja083e8f2-7d9d-4b50-9815-8b423b728001 From: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef To: "6001" ;tag=6d9cbcf322115fc5o0 Contact: Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 16170 REFER Event: refer Expires: 600 Supported: 100rel, timer, replaces, norefersub Accept: message/sipfrag;version=2.0 Allow-Events: presence, dialog, message-summary, refer Refer-To: 6002 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..State changed from Null to Calling, event=TX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Transaction tsx0x7fde58006718 state changed to Calling [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Calling [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 20 20:37:06] DEBUG[25101] pjsip: evsub0x7fde580 ....Subscription state changed NULL --> SENT [Aug 20 20:37:06] DEBUG[25157][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/6001-00000000' [Aug 20 20:37:06] DEBUG[25157][C-00000000] channel.c: Hanging up channel 'PJSIP/6001-00000000' [Aug 20 20:37:06] DEBUG[25157][C-00000000] chan_pjsip.c: AST hangup cause 0 (no match found in PJSIP) [Aug 20 20:37:06] DEBUG[25101] pjsip: endpoint .Request msg BYE/cseq=16172 (tdta0x7fde58004140) created. [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Method is BYE [Aug 20 20:37:06] DEBUG[25101] pjsip: inv0x7fde58005 .Sending Request msg BYE/cseq=16172 (tdta0x7fde58004140) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ..Sending Request msg BYE/cseq=16172 (tdta0x7fde58004140) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58011 ...Transaction created for Request msg BYE/cseq=16171 (tdta0x7fde58004140) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58011 ..Sending Request msg BYE/cseq=16171 (tdta0x7fde58004140) in state Null [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_resolve.c ...Target '192.168.1.245:5060' type=Unspecified resolved to '192.168.1.245:5060' type=UDP (UDP transport) [Aug 20 20:37:06] VERBOSE[25101] res_pjsip_logger.c: <--- Transmitting SIP request (374 bytes) to UDP:192.168.1.245:5060 ---> BYE sip:6001@192.168.1.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.187:5060;rport;branch=z9hG4bKPj885ea597-27ea-4e46-9ff7-0f5ff1e88ae6 From: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef To: "6001" ;tag=6d9cbcf322115fc5o0 Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 16171 BYE Reason: Q.850;cause=0 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58011 ...State changed from Null to Calling, event=TX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ....Transaction tsx0x7fde58011438 state changed to Calling [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58011438 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Calling [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 20 20:37:06] DEBUG[25094] cdr.c: Finalized CDR for PJSIP/6001-00000000 - start 1408585026.600425 answer 1408585026.601022 end 1408585026.627163 dispo ANSWERED [Aug 20 20:37:06] DEBUG[25092] devicestate.c: No provider found, checking channel drivers for PJSIP - 6001 [Aug 20 20:37:06] DEBUG[25092] devicestate.c: Changing state for PJSIP/6001 - state 1 (Not in use) [Aug 20 20:37:06] DEBUG[25151] app_queue.c: Device 'PJSIP/6001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Response msg 400/REFER/cseq=16170 (rdata0x7fde280038c8) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP response (360 bytes) from UDP:192.168.1.245:5060 ---> SIP/2.0 400 Bad Request To: "6001" ;tag=6d9cbcf322115fc5o0 From: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 16170 REFER Via: SIP/2.0/UDP 192.168.1.187:5060;branch=z9hG4bKPja083e8f2-7d9d-4b50-9815-8b423b728001 Server: Linksys/SPA942-5.2.8 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 400/REFER/cseq=16170 (rdata0x7fde280070b8) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 .Incoming Response msg 400/REFER/cseq=16170 (rdata0x7fde280070b8) in state Calling [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58006 ..State changed from Calling to Completed, event=RX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Received Response msg 400/REFER/cseq=16170 (rdata0x7fde280070b8) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Transaction tsx0x7fde58006718 state changed to Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 20 20:37:06] DEBUG[25101] pjsip: evsub0x7fde580 ....Subscription state changed SENT --> TERMINATED [Aug 20 20:37:06] DEBUG[25106] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=16171 (rdata0x7fde280038c8) [Aug 20 20:37:06] VERBOSE[25106] res_pjsip_logger.c: <--- Received SIP response (349 bytes) from UDP:192.168.1.245:5060 ---> SIP/2.0 200 OK To: "6001" ;tag=6d9cbcf322115fc5o0 From: ;tag=8fccb7b2-7421-4a32-b341-d5c3ae03c2ef Call-ID: ef0c4f0b-ac2d348d@192.168.1.245 CSeq: 16171 BYE Via: SIP/2.0/UDP 192.168.1.187:5060;branch=z9hG4bKPj885ea597-27ea-4e46-9ff7-0f5ff1e88ae6 Server: Linksys/SPA942-5.2.8 Content-Length: 0 [Aug 20 20:37:06] DEBUG[25101] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/BYE/cseq=16171 (rdata0x7fde280070b8) [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58011 .Incoming Response msg 200/BYE/cseq=16171 (rdata0x7fde280070b8) in state Calling [Aug 20 20:37:06] DEBUG[25101] pjsip: tsx0x7fde58011 ..State changed from Calling to Completed, event=RX_MSG [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Received Response msg 200/BYE/cseq=16171 (rdata0x7fde280070b8) [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 ...Transaction tsx0x7fde58011438 state changed to Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The state change pertains to the session with 6001 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: There is no transaction involved in this state change [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Source of transaction state change is RX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Received response [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Response is 200 OK [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Destroying SIP session with endpoint 6001 [Aug 20 20:37:06] DEBUG[25101] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] rtp_engine.c: Destroyed RTP instance '0x7fde58012738' [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .....Session count dec to 3 by Session Module [Aug 20 20:37:06] DEBUG[25101] pjsip: dlg0x7fde58005 .....Session count dec to 2 by mod-invite [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: inv_session 0x7fde580076a8 has no ast session [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58011438 [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current transaction state is Completed [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 20 20:37:06] DEBUG[25101] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 20 20:37:06] DEBUG[25101] taskprocessor.c: destroying taskprocessor '2830cea4-a534-4f5a-a0af-4e14a06afb1f' [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58006 Timeout timer event [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58006 .State changed from Completed to Terminated, event=TIMER [Aug 20 20:37:11] DEBUG[25106] pjsip: dlg0x7fde58005 ..Transaction tsx0x7fde58006718 state changed to Terminated [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: inv_session 0x7fde580076a8 has no ast session [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58006718 [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The current transaction state is Terminated [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The transaction state change event is TIMER [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 20 20:37:11] DEBUG[25106] pjsip: evsub0x7fde580 ...Subscription destroyed [Aug 20 20:37:11] DEBUG[25106] pjsip: dlg0x7fde58005 ....Session count dec to 1 by mod-evsub [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58006 Timeout timer event [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58006 .State changed from Terminated to Destroyed, event=TIMER [Aug 20 20:37:11] DEBUG[25106] pjsip: tdta0x7fde2800 ..Destroying txdata Request msg REFER/cseq=16170 (tdta0x7fde280008e0) [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58006 Transaction destroyed! [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58011 Timeout timer event [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58011 .State changed from Completed to Terminated, event=TIMER [Aug 20 20:37:11] DEBUG[25106] pjsip: dlg0x7fde58005 ..Transaction tsx0x7fde58011438 state changed to Terminated [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: inv_session 0x7fde580076a8 has no ast session [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The transaction involved in this state change is 0x7fde58011438 [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The current transaction state is Terminated [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The transaction state change event is TIMER [Aug 20 20:37:11] DEBUG[25106] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 20 20:37:11] DEBUG[25106] pjsip: dlg0x7fde58005 ...Dialog destroyed [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58011 Timeout timer event [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58011 .State changed from Terminated to Destroyed, event=TIMER [Aug 20 20:37:11] DEBUG[25106] pjsip: tdta0x7fde5800 ..Destroying txdata Request msg BYE/cseq=16171 (tdta0x7fde58004140) [Aug 20 20:37:11] DEBUG[25106] pjsip: tsx0x7fde58011 Transaction destroyed! [Aug 20 20:37:15] DEBUG[25155] cdr.c: CDR Engine termination request received; waiting on messages... [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor 'ast_msg_queue' [Aug 20 20:37:15] VERBOSE[25155] asterisk.c: Asterisk cleanly ending (0). [Aug 20 20:37:15] VERBOSE[25155] asterisk.c: Executing last minute cleanups [Aug 20 20:37:15] DEBUG[25155] res_musiconhold.c: Destroying MOH class 'default' [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor '885f400e-6bf1-4d8c-905c-1480b9eeff39' [Aug 20 20:37:15] DEBUG[25155] logger.c: Unregistered dynamic logger level 'CC' with index 16. [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor 'CCSS core' [Aug 20 20:37:15] DEBUG[25155] tcptls.c: Stopped server :: AMI server [Aug 20 20:37:15] DEBUG[25155] tcptls.c: Stopped server :: AMI TLS server [Aug 20 20:37:15] DEBUG[25155] channel.c: Unregistering channel type 'Local' [Aug 20 20:37:15] DEBUG[25096] taskprocessor.c: destroying taskprocessor 'b4c26d22-e0a5-43f4-9224-426589dfa57f' [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor 'f10bb18e-3843-4dee-82b5-4d9efe2f2bc0' [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor '8aa49899-5849-4842-bae5-27ab689f3ca8' [Aug 20 20:37:15] DEBUG[25155] tcptls.c: Stopped server :: http server [Aug 20 20:37:15] DEBUG[25155] bridge.c: Waiting for bridge manager thread to die. [Aug 20 20:37:15] DEBUG[25155] channel.c: Unregistering channel type 'Surrogate' [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor 'Sorcery-control' [Aug 20 20:37:15] DEBUG[25155] threadpool.c: Destroying worker thread 5 [Aug 20 20:37:15] DEBUG[25155] taskprocessor.c: destroying taskprocessor 'Sorcery' [Aug 20 20:37:15] DEBUG[25155] asterisk.c: Asterisk ending (0).