[Jun 18 15:46:23] Asterisk GIT-13-723a9d4 built by rnewton @ newtonr-laptop on a x86_64 running Linux on 2015-05-27 16:13:50 UTC [Jun 18 15:46:23] DEBUG[20622] config.c: Parsing /etc/asterisk/logger.conf [Jun 18 15:46:47] DEBUG[20576] pjsip: tsx0x7fe43000f Timeout timer event [Jun 18 15:46:47] DEBUG[20576] pjsip: tsx0x7fe43000f .State changed from Completed to Terminated, event=TIMER [Jun 18 15:46:47] DEBUG[20576] pjsip: tsx0x7fe43000f Timeout timer event [Jun 18 15:46:47] DEBUG[20576] pjsip: tsx0x7fe43000f .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:46:47] DEBUG[20576] pjsip: tdta0x7fe4483e ..Destroying txdata Response msg 200/REGISTER/cseq=4428 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20576] pjsip: tsx0x7fe43000f Transaction destroyed! [Jun 18 15:46:47] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=16638 (rdata0x7fe44833d648) [Jun 18 15:46:47] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (1082 bytes) from UDP:10.24.18.16:5060 ---> INVITE sip:102@10.24.18.124 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjg4MIC4E5PzR02mSBdw-SHWVVypAnlTa8 Max-Forwards: 70 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: Contact: "Lindsey Freddie" Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 CSeq: 16638 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: Digium D40 1_4_2_0_63880 Content-Type: application/sdp Content-Length: 430 v=0 o=- 130031701 130031701 IN IP4 10.24.18.16 s=digphn c=IN IP4 10.24.18.16 t=0 0 a=X-nat:0 m=audio 4058 RTP/AVP 111 18 0 58 118 9 8 58 96 a=rtcp:4059 IN IP4 10.24.18.16 a=rtpmap:111 G726-32/8000 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:58 L16/16000 a=rtpmap:118 L16/8000 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:58 L16-256/16000 a=sendrecv a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=16638 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint ALICE [Jun 18 15:46:47] DEBUG[20912] pjsip: endpoint .Response msg 401/INVITE/cseq=16638 (tdta0x7fe43003ab20) created [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (572 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjg4MIC4E5PzR02mSBdw-SHWVVypAnlTa8 Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=z9hG4bKPjg4MIC4E5PzR02mSBdw-SHWVVypAnlTa8 CSeq: 16638 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1434660407/10c9631c280282f40ab98ae020041049",opaque="4ecac929278785bd",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:47] DEBUG[20912] pjsip: tdta0x7fe43003 .Destroying txdata Response msg 401/INVITE/cseq=16638 (tdta0x7fe43003ab20) [Jun 18 15:46:47] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=16638 (rdata0x7fe44833d648) [Jun 18 15:46:47] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (385 bytes) from UDP:10.24.18.16:5060 ---> ACK sip:102@10.24.18.124 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjg4MIC4E5PzR02mSBdw-SHWVVypAnlTa8 Max-Forwards: 70 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=z9hG4bKPjg4MIC4E5PzR02mSBdw-SHWVVypAnlTa8 Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 CSeq: 16638 ACK Content-Length: 0 [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=16638 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint ALICE [Jun 18 15:46:47] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=16639 (rdata0x7fe44833d648) [Jun 18 15:46:47] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (1374 bytes) from UDP:10.24.18.16:5060 ---> INVITE sip:102@10.24.18.124 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjBMWF7otbEA7aYUS2nVALliEaXv-TkrFc Max-Forwards: 70 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: Contact: "Lindsey Freddie" Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 CSeq: 16639 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: Digium D40 1_4_2_0_63880 Authorization: Digest username="ALICE", realm="asterisk", nonce="1434660407/10c9631c280282f40ab98ae020041049", uri="sip:102@10.24.18.124", response="859dfc7b897364cb009d0d495a574d6c", algorithm=md5, cnonce="LVPBY2HDT-.BjK64KQ6mtVflvA3.WulE", opaque="4ecac929278785bd", qop=auth, nc=00000001 Content-Type: application/sdp Content-Length: 430 v=0 o=- 130031701 130031701 IN IP4 10.24.18.16 s=digphn c=IN IP4 10.24.18.16 t=0 0 a=X-nat:0 m=audio 4058 RTP/AVP 111 18 0 58 118 9 8 58 96 a=rtcp:4059 IN IP4 10.24.18.16 a=rtpmap:111 G726-32/8000 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:58 L16/16000 a=rtpmap:118 L16/8000 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:58 L16-256/16000 a=sendrecv a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=16639 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:46:47] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint ALICE [Jun 18 15:46:47] DEBUG[20912] pjsip: endpoint .Response msg 401/INVITE/cseq=16639 (tdta0x7fe43003ab20) created [Jun 18 15:46:47] DEBUG[20912] res_pjsip_authenticator_digest.c: Calculated nonce 1434660407/10c9631c280282f40ab98ae020041049. Actual nonce is 1434660407/10c9631c280282f40ab98ae020041049 [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:47] DEBUG[20912] pjsip: tdta0x7fe43003 .Destroying txdata Response msg 401/INVITE/cseq=16639 (tdta0x7fe43003ab20) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ..Transaction created for Request msg INVITE/cseq=16639 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 .Incoming Request msg INVITE/cseq=16639 (rdata0x7fe44800e9d8) in state Null [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ..State changed from Null to Trying, event=RX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ...Transaction tsx0x7fe4300329d8 state changed to Trying [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f .UAS dialog created [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f .Module mod-invite added as dialog usage, data=0x7fe4800067a8 [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ..Session count inc to 2 by mod-invite [Jun 18 15:46:47] DEBUG[20912] pjsip: inv0x7fe43000f .UAS invite session created for dialog dlg0x7fe43000fda8 [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f .Module Session Module added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ..Session count inc to 2 by Session Module [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fe4800110a8' [Jun 18 15:46:47] DEBUG[20912] res_rtp_asterisk.c: Allocated port 16520 for RTP instance '0x7fe4800110a8' [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 ICE session created, comp_cnt=2, role is Unknown agent [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 0 added: comp_id=1, type=host, foundation=Ha18127c, addr=10.24.18.124:16520, base=10.24.18.124:16520, prio=0x7effffff (2130706431) [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: RTP instance '0x7fe4800110a8' is setup and ready to go [Jun 18 15:46:47] DEBUG[20912] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fe4800110a8' [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 1 added: comp_id=2, type=host, foundation=Ha18127c, addr=10.24.18.124:16521, base=10.24.18.124:16521, prio=0x7efffffe (2130706430) [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Destroying ICE session 0x7fe480014c18 [Jun 18 15:46:47] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe480017458 destroy request, ref_cnt=4 [Jun 18 15:46:47] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe480018458 destroy request, ref_cnt=3 [Jun 18 15:46:47] DEBUG[20912] pjsip: ice_session.c ICE session 0x7fe480014c18 destroyed [Jun 18 15:46:47] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe480017458 destroyed [Jun 18 15:46:47] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe480018458 destroyed [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 111 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 18 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 0 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 58 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 118 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 9 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 8 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 58 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Setting payload 96 (0x7fe480017ed8) based on m type on 0x7fe43f11a680 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 0 (0x7fe480018d08) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 8 (0x7fe480016238) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 9 (0x7fe480015dd8) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 18 (0x7fe4800188a8) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 58 (0x7fe480015408) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 96 (0x7fe480016b88) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 111 (0x7fe480018338) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Copying payload 118 (0x7fe480015978) from 0x7fe43f11a680 to 0x7fe480011270 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Media stream 'audio' handled by audio [Jun 18 15:46:47] DEBUG[20912] pjsip: endpoint .Response msg 100/INVITE/cseq=16639 (tdta0x7fe4483e92a0) created [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f .Initial answer Response msg 100/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jun 18 15:46:47] DEBUG[20912] pjsip: inv0x7fe43000f .Sending Response msg 100/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ..Sending Response msg 100/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ..Sending Response msg 100/INVITE/cseq=16639 (tdta0x7fe4483e92a0) in state Trying [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (373 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjBMWF7otbEA7aYUS2nVALliEaXv-TkrFc Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: CSeq: 16639 INVITE Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Trying to Proceeding, event=TX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ....Transaction tsx0x7fe4300329d8 state changed to Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE()' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is INCOMING [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE()' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is INCOMING [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f Module NAT added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20548] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jun 18 15:46:47] DEBUG[20912] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/ALICE-00000009 [Jun 18 15:46:47] DEBUG[20921][C-00000003] pbx.c: Launching 'Dial' [Jun 18 15:46:47] DEBUG[20912] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Jun 18 15:46:47] DEBUG[20912] config.c: extract int from [0] in [0, 86400] gives [0](0) [Jun 18 15:46:47] DEBUG[20912] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 UAC dialog created [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module Outbound INVITE Auth added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module mod-invite added as dialog usage, data=0x7fe48001a7b8 [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 .Session count inc to 2 by mod-invite [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module mod-100rel added as dialog usage, data=0x7fe48001a978 [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 100rel module attached [Jun 18 15:46:47] DEBUG[20912] pjsip: inv0x7fe430019 UAC invite session created for dialog dlg0x7fe430019228 [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 .Session count inc to 2 by Session Module [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module Session Module added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fe480017488' [Jun 18 15:46:47] DEBUG[20912] res_rtp_asterisk.c: Allocated port 18680 for RTP instance '0x7fe480017488' [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 ICE session created, comp_cnt=2, role is Unknown agent [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 0 added: comp_id=1, type=host, foundation=Ha18127c, addr=10.24.18.124:18680, base=10.24.18.124:18680, prio=0x7effffff (2130706431) [Jun 18 15:46:47] DEBUG[20912] rtp_engine.c: RTP instance '0x7fe480017488' is setup and ready to go [Jun 18 15:46:47] DEBUG[20912] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fe480017488' [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 1 added: comp_id=2, type=host, foundation=Ha18127c, addr=10.24.18.124:18681, base=10.24.18.124:18681, prio=0x7efffffe (2130706430) [Jun 18 15:46:47] DEBUG[20912] pjsip: icess0x7fe4800 Destroying ICE session 0x7fe48000e588 [Jun 18 15:46:47] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe480014838 destroy request, ref_cnt=4 [Jun 18 15:46:47] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe480010598 destroy request, ref_cnt=3 [Jun 18 15:46:47] DEBUG[20912] pjsip: ice_session.c ICE session 0x7fe48000e588 destroyed [Jun 18 15:46:47] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe480014838 destroyed [Jun 18 15:46:47] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe480010598 destroyed [Jun 18 15:46:47] DEBUG[20912] pjsip: endpoint Request msg INVITE/cseq=9526 (tdta0x7fe43003ab20) created. [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module WebSocket Transport Module added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 Module NAT added as dialog usage, data=(nil) [Jun 18 15:46:47] DEBUG[20912] pjsip: inv0x7fe430019 .Sending Request msg INVITE/cseq=9526 (tdta0x7fe43003ab20) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ..Sending Request msg INVITE/cseq=9526 (tdta0x7fe43003ab20) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 ...Transaction created for Request msg INVITE/cseq=9525 (tdta0x7fe43003ab20) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 ..Sending Request msg INVITE/cseq=9525 (tdta0x7fe43003ab20) in state Null [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_resolve.c ...Target '10.24.18.138:5060' type=Unspecified resolved to '10.24.18.138:5060' type=UDP (UDP transport) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.24.18.124:5060 [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:46:47] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP request (945 bytes) to UDP:10.24.18.138:5060 ---> INVITE sip:BOB@10.24.18.138:5060;ob SIP/2.0 Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjc6b66f3e-6ff8-4c66-99bd-fdeef0e1e651 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: Contact: Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 CSeq: 9525 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-723a9d4 Content-Type: application/sdp Content-Length: 237 v=0 o=- 1001234369 1001234369 IN IP4 10.24.18.124 s=Asterisk c=IN IP4 10.24.18.124 t=0 0 m=audio 18680 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 ...State changed from Null to Calling, event=TX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ....Transaction tsx0x7fe4300366f8 state changed to Calling [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current transaction state is Calling [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:47] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 100/INVITE/cseq=9525 (rdata0x7fe44833d648) [Jun 18 15:46:47] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (352 bytes) from UDP:10.24.18.138:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.24.18.124:5060;rport=5060;received=10.24.18.124;branch=z9hG4bKPjc6b66f3e-6ff8-4c66-99bd-fdeef0e1e651 Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: CSeq: 9525 INVITE Content-Length: 0 [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 100/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 .Incoming Response msg 100/INVITE/cseq=9525 (rdata0x7fe44800e9d8) in state Calling [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 ..State changed from Calling to Proceeding, event=RX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ...Received Response msg 100/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ...Transaction tsx0x7fe4300366f8 state changed to Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Response is 100 Trying [Jun 18 15:46:47] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=9525 (rdata0x7fe44833d648) [Jun 18 15:46:47] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (577 bytes) from UDP:10.24.18.138:5060 ---> SIP/2.0 180 ringing Via: SIP/2.0/UDP 10.24.18.124:5060;rport=5060;received=10.24.18.124;branch=z9hG4bKPjc6b66f3e-6ff8-4c66-99bd-fdeef0e1e651 Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: ;tag=HWywDY8Dof4N36poqS-zSbqEhc-XOs3O CSeq: 9525 INVITE Contact: "Temple Morgan" Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS User-Agent: Digium D40 1_4_2_0_63880 Content-Length: 0 [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:46:47] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 180/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 .Incoming Response msg 180/INVITE/cseq=9525 (rdata0x7fe44800e9d8) in state Proceeding [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430036 ..State changed from Proceeding to Proceeding, event=RX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ...Received Response msg 180/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ....Route-set updated [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe430019 ...Transaction tsx0x7fe4300366f8 state changed to Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Response is 180 ringing [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Response is 180 ringing [Jun 18 15:46:47] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - BOB [Jun 18 15:46:47] DEBUG[20560] devicestate.c: Changing state for PJSIP/BOB - state 6 (Ringing) [Jun 18 15:46:47] DEBUG[20618] app_queue.c: Device 'PJSIP/BOB' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jun 18 15:46:47] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - ALICE [Jun 18 15:46:47] DEBUG[20560] devicestate.c: Changing state for PJSIP/ALICE - state 2 (In use) [Jun 18 15:46:47] DEBUG[20618] app_queue.c: Device 'PJSIP/ALICE' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jun 18 15:46:47] DEBUG[20912] pjsip: inv0x7fe43000f .Sending Response msg 180/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ..Sending Response msg 180/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ..Sending Response msg 180/INVITE/cseq=16639 (tdta0x7fe4483e92a0) in state Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.24.18.124:5060 [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:47] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:47] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:47] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (560 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjBMWF7otbEA7aYUS2nVALliEaXv-TkrFc Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=b597b99e-401c-46d5-827b-d0fee3fa9880 CSeq: 16639 INVITE Server: Asterisk PBX GIT-13-723a9d4 Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Content-Length: 0 [Jun 18 15:46:47] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Proceeding to Proceeding, event=TX_MSG [Jun 18 15:46:47] DEBUG[20912] pjsip: dlg0x7fe43000f ....Transaction tsx0x7fe4300329d8 state changed to Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:47] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jun 18 15:46:50] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/INVITE/cseq=9525 (rdata0x7fe44833d648) [Jun 18 15:46:50] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (974 bytes) from UDP:10.24.18.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.18.124:5060;rport=5060;received=10.24.18.124;branch=z9hG4bKPjc6b66f3e-6ff8-4c66-99bd-fdeef0e1e651 Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: ;tag=HWywDY8Dof4N36poqS-zSbqEhc-XOs3O CSeq: 9525 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS User-Agent: Digium D40 1_4_2_0_63880 Contact: "Temple Morgan" Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800;refresher=uac User-Agent: Digium D40 1_4_2_0_63880 Content-Type: application/sdp Content-Length: 245 v=0 o=- 130031700 130031701 IN IP4 10.24.18.138 s=digphn c=IN IP4 10.24.18.138 t=0 0 a=X-nat:0 m=audio 4024 RTP/AVP 0 96 a=rtcp:4025 IN IP4 10.24.18.138 a=rtpmap:0 PCMU/8000 a=sendrecv a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 [Jun 18 15:46:50] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:46:50] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:46:50] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:50] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:50] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430036 .Incoming Response msg 200/INVITE/cseq=9525 (rdata0x7fe44800e9d8) in state Proceeding [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430036 ..State changed from Proceeding to Terminated, event=RX_MSG [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe430019 ...Received Response msg 200/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe430019 ....Route-set updated [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe430019 ....Route-set frozen [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe430019 ...Transaction tsx0x7fe4300366f8 state changed to Terminated [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONNECTING [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Response is 200 OK [Jun 18 15:46:50] DEBUG[20912] pjsip: inv0x7fe430019 ....Got SDP answer in Response msg 200/INVITE/cseq=9525 (rdata0x7fe44800e9d8) [Jun 18 15:46:50] DEBUG[20912] pjsip: inv0x7fe430019 ....SDP negotiation done, status=0 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '10.24.18.138' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port ''. [Jun 18 15:46:50] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe480017488' [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Setting payload 0 (0x7fe480009318) based on m type on 0x7fe43f119e90 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Setting payload 101 (0x7fe480009318) based on m type on 0x7fe43f119e90 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Copying payload 0 (0x7fe480009418) from 0x7fe43f119e90 to 0x7fe480017650 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Copying payload 101 (0x7fe48001abe8) from 0x7fe43f119e90 to 0x7fe480017650 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:46:50] DEBUG[20912] pjsip: inv0x7fe430019 ....Received Response msg 200/INVITE/cseq=9525 (rdata0x7fe44800e9d8), sending ACK [Jun 18 15:46:50] DEBUG[20912] pjsip: endpoint ....Request msg ACK/cseq=9525 (tdta0x7fe430013410) created. [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe430019 .....Sending Request msg ACK/cseq=9525 (tdta0x7fe430013410) [Jun 18 15:46:50] DEBUG[20912] pjsip: sip_resolve.c .....Target '10.24.18.138:5060' type=Unspecified resolved to '10.24.18.138:5060' type=UDP (UDP transport) [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: 0x7fe48001b7b0 -- Probation learning mode pass with source address 10.24.18.138:4024 [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe4800110a8' so dropping frame [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe4800110a8' so dropping frame [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe4800110a8' so dropping frame [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:46:50] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP request (440 bytes) to UDP:10.24.18.138:5060 ---> ACK sip:BOB@10.24.18.138:5060;ob SIP/2.0 Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjef41b107-07fe-4550-b6cc-002083264904 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: ;tag=HWywDY8Dof4N36poqS-zSbqEhc-XOs3O Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 CSeq: 9525 ACK Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300366f8) [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Method is ACK [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current transaction state is Terminated [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Response is 200 OK [Jun 18 15:46:50] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - BOB [Jun 18 15:46:50] DEBUG[20560] devicestate.c: Changing state for PJSIP/BOB - state 2 (In use) [Jun 18 15:46:50] DEBUG[20618] app_queue.c: Device 'PJSIP/BOB' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:46:50] DEBUG[20548] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jun 18 15:46:50] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - ALICE [Jun 18 15:46:50] DEBUG[20560] devicestate.c: Changing state for PJSIP/ALICE - state 2 (In use) [Jun 18 15:46:50] DEBUG[20912] pjsip: inv0x7fe43000f .SDP negotiation done, status=0 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:50] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe4800110a8' [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Setting payload 0 (0x7fe480009318) based on m type on 0x7fe43f11a070 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Setting payload 96 (0x7fe480009318) based on m type on 0x7fe43f11a070 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Copying payload 0 (0x7fe480002d58) from 0x7fe43f11a070 to 0x7fe480011270 [Jun 18 15:46:50] DEBUG[20912] rtp_engine.c: Copying payload 96 (0x7fe480007b48) from 0x7fe43f11a070 to 0x7fe480011270 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jun 18 15:46:50] DEBUG[20912] pjsip: inv0x7fe43000f .Sending Response msg 200/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe43000f ..Sending Response msg 200/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430032 ..Sending Response msg 200/INVITE/cseq=16639 (tdta0x7fe4483e92a0) in state Proceeding [Jun 18 15:46:50] DEBUG[20912] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.24.18.124:5060 [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:50] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:50] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:50] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (922 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjBMWF7otbEA7aYUS2nVALliEaXv-TkrFc Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=b597b99e-401c-46d5-827b-d0fee3fa9880 CSeq: 16639 INVITE Server: Asterisk PBX GIT-13-723a9d4 Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Contact: Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800;refresher=uac Require: timer Content-Type: application/sdp Content-Length: 232 v=0 o=- 130031701 130031703 IN IP4 10.24.18.124 s=Asterisk c=IN IP4 10.24.18.124 t=0 0 m=audio 16520 RTP/AVP 0 96 a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Proceeding to Completed, event=TX_MSG [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe43000f ....Transaction tsx0x7fe4300329d8 state changed to Completed [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONNECTING [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONNECTING [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as two channels are required [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: calling simple_bridge technology constructor [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: calling simple_bridge technology start [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004778(PJSIP/ALICE-00000009) is joining [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004608(PJSIP/BOB-0000000a) is joining [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pushing 0x7fe450004778(PJSIP/ALICE-00000009) [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as two channels are required [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:46:50] DEBUG[20921][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004778(PJSIP/ALICE-00000009) is joining simple_bridge technology [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pushing 0x7fe450004608(PJSIP/BOB-0000000a) [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as channel 'PJSIP/ALICE-00000009' has DTMF hooks [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:46:50] DEBUG[20923][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004608(PJSIP/BOB-0000000a) is joining simple_bridge technology [Jun 18 15:46:50] DEBUG[20561] cdr.c: Finalized CDR for PJSIP/BOB-0000000a - start 1434660407.852631 answer 1434660410.539219 end 1434660410.541713 dispo ANSWERED [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430036 Timeout timer event [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430036 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430036 Transaction destroyed! [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7fe4800110a8' [Jun 18 15:46:50] DEBUG[20921][C-00000003] res_rtp_asterisk.c: 0x7fe480011db0 -- Probation learning mode pass with source address 10.24.18.16:4058 [Jun 18 15:46:50] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Ooh, format changed from none to ulaw [Jun 18 15:46:50] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=16639 (rdata0x7fe44833d648) [Jun 18 15:46:50] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (381 bytes) from UDP:10.24.18.16:5060 ---> ACK sip:10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjsfMA-5ZoV4IgYLl.ssGHCV6lDo4I-uqk Max-Forwards: 70 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=b597b99e-401c-46d5-827b-d0fee3fa9880 Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 CSeq: 16639 ACK Content-Length: 0 [Jun 18 15:46:50] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:50] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:50] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:50] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:50] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=16639 (rdata0x7fe44800e9d8) [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe43000f .Received Request msg ACK/cseq=16639 (rdata0x7fe44800e9d8) [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430032 ..Request to terminate transaction [Jun 18 15:46:50] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Completed to Terminated, event=USER [Jun 18 15:46:50] DEBUG[20912] pjsip: dlg0x7fe43000f ....Transaction tsx0x7fe4300329d8 state changed to Terminated [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current transaction state is Terminated [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The transaction state change event is USER [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONNECTING [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Received request [Jun 18 15:46:50] DEBUG[20912] res_pjsip_session.c: Method is ACK [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430032 Timeout timer event [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430032 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:46:50] DEBUG[20576] pjsip: tdta0x7fe4483e ..Destroying txdata Response msg 200/INVITE/cseq=16639 (tdta0x7fe4483e92a0) [Jun 18 15:46:50] DEBUG[20576] pjsip: tsx0x7fe430032 Transaction destroyed! [Jun 18 15:46:50] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:46:50] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:50] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:50] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:50] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:50] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:46:50] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:46:50] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:46:50] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:50] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:52] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 42 (*), at 10.24.18.16:4058 [Jun 18 15:46:52] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating END DTMF Frame: 42 (*), at 10.24.18.16:4058 [Jun 18 15:46:52] DEBUG[20921][C-00000003] bridge_channel.c: DTMF feature string on 0x7fe450004778(PJSIP/ALICE-00000009) is now '*' [Jun 18 15:46:52] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 50 (2), at 10.24.18.16:4058 [Jun 18 15:46:52] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating END DTMF Frame: 50 (2), at 10.24.18.16:4058 [Jun 18 15:46:52] DEBUG[20921][C-00000003] bridge_channel.c: DTMF feature string on 0x7fe450004778(PJSIP/ALICE-00000009) is now '*2' [Jun 18 15:46:52] DEBUG[20921][C-00000003] bridge_channel.c: DTMF feature hook 0x7fe45000ab30 matched DTMF string '*2' on 0x7fe450004778(PJSIP/ALICE-00000009) [Jun 18 15:46:52] DEBUG[20921][C-00000003] bridge_basic.c: Allocated attended transfer properties 0x7fe4500014a8 for transfer from PJSIP/ALICE-00000009 [Jun 18 15:46:52] DEBUG[20921][C-00000003] bridge_roles.c: Set role 'transferer' [Jun 18 15:46:52] DEBUG[20618] app_queue.c: Device 'PJSIP/BOB' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Jun 18 15:46:52] DEBUG[20923][C-00000003] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 18 15:46:52] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: gsm -> ulaw [Jun 18 15:46:52] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 18 15:46:52] DEBUG[20923][C-00000003] channel.c: Channel PJSIP/BOB-0000000a setting write format path: slin -> ulaw [Jun 18 15:46:52] DEBUG[20923][C-00000003] res_musiconhold.c: PJSIP/BOB-0000000a Opened file 0 '/var/lib/asterisk/moh/macroform-cold_day' [Jun 18 15:46:52] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Difference is 1208, ms is 171 [Jun 18 15:46:53] DEBUG[20576] pjsip: tsx0x7fe430015 Timeout timer event [Jun 18 15:46:53] DEBUG[20576] pjsip: tsx0x7fe430015 .State changed from Completed to Terminated, event=TIMER [Jun 18 15:46:53] DEBUG[20576] pjsip: tsx0x7fe430015 Timeout timer event [Jun 18 15:46:53] DEBUG[20576] pjsip: tsx0x7fe430015 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:46:53] DEBUG[20576] pjsip: tdta0x7fe43000 ..Destroying txdata Response msg 200/REGISTER/cseq=50306 (tdta0x7fe430005a00) [Jun 18 15:46:53] DEBUG[20576] pjsip: tsx0x7fe430015 Transaction destroyed! [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: ulaw -> ulaw [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: slin -> ulaw [Jun 18 15:46:53] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 18 15:46:54] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 49 (1), at 10.24.18.16:4058 [Jun 18 15:46:54] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating END DTMF Frame: 49 (1), at 10.24.18.16:4058 [Jun 18 15:46:54] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: ulaw -> ulaw [Jun 18 15:46:54] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:54] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 48 (0), at 10.24.18.16:4058 [Jun 18 15:46:54] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating END DTMF Frame: 48 (0), at 10.24.18.16:4058 [Jun 18 15:46:54] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating BEGIN DTMF Frame: 51 (3), at 10.24.18.16:4058 [Jun 18 15:46:55] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Creating END DTMF Frame: 51 (3), at 10.24.18.16:4058 [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge_basic.c: Attended transfer to '103@from-internal' [Jun 18 15:46:55] DEBUG[20921][C-00000003] channel_internal_api.c: Channel Call ID changing from [C-00000003] to [C-00000003] [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge_native_rtp.c: Bridge 'fe18974d-cf6c-4e06-93e3-5104e70626f2' can not use native RTP bridge as two channels are required [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: calling simple_bridge technology constructor [Jun 18 15:46:55] DEBUG[20921][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: calling simple_bridge technology start [Jun 18 15:46:55] DEBUG[20924][C-00000003] pbx.c: Launching 'Dial' [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: 0x7fe45000f958(Local/103@from-internal-00000003;1) is joining [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_basic.c: About to enter state Calling Target for attended transfer 0x7fe4500014a8 [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: pushing 0x7fe45000f958(Local/103@from-internal-00000003;1) [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge_native_rtp.c: Bridge 'fe18974d-cf6c-4e06-93e3-5104e70626f2' can not use native RTP bridge as two channels are required [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 is already using the new technology. [Jun 18 15:46:55] DEBUG[20925][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: 0x7fe45000f958(Local/103@from-internal-00000003;1) is joining simple_bridge technology [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Moving 0x7fe450004778(PJSIP/ALICE-00000009) into bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pulling 0x7fe450004778(PJSIP/ALICE-00000009) [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004778(PJSIP/ALICE-00000009) is leaving simple_bridge technology [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: pushing 0x7fe450004778(PJSIP/ALICE-00000009) [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_roles.c: Set role 'transferer' [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_native_rtp.c: Bridge 'fe18974d-cf6c-4e06-93e3-5104e70626f2' can not use native RTP bridge as it was forbidden while getting details [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 is already using the new technology. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: 0x7fe450004778(PJSIP/ALICE-00000009) is joining simple_bridge technology [Jun 18 15:46:55] DEBUG[20912] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Jun 18 15:46:55] DEBUG[20912] config.c: extract int from [0] in [0, 86400] gives [0](0) [Jun 18 15:46:55] DEBUG[20912] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as two channels are required [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:55] DEBUG[20926][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 UAC dialog created [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module Outbound INVITE Auth added as dialog usage, data=(nil) [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module mod-invite added as dialog usage, data=0x7fe48002dce8 [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 .Session count inc to 2 by mod-invite [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module mod-100rel added as dialog usage, data=0x7fe48002dea8 [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 100rel module attached [Jun 18 15:46:55] DEBUG[20912] pjsip: inv0x7fe430015 UAC invite session created for dialog dlg0x7fe430015b18 [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 .Session count inc to 2 by Session Module [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module Session Module added as dialog usage, data=(nil) [Jun 18 15:46:55] DEBUG[20561] cdr.c: Finalized CDR for PJSIP/ALICE-00000009 - start 1434660407.850537 answer 1434660410.539792 end 1434660415.108637 dispo ANSWERED [Jun 18 15:46:55] DEBUG[20561] cdr.c: Finalized CDR for Local/103@from-internal-00000003;1 - start 1434660415.106335 answer 0.000000 end 1434660415.108713 dispo FAILED [Jun 18 15:46:55] DEBUG[20924][C-00000003] rtp_engine.c: Can't find native functions for channel 'Local/103@from-internal-00000003;2' [Jun 18 15:46:55] DEBUG[20912] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fe48000b618' [Jun 18 15:46:55] DEBUG[20912] res_rtp_asterisk.c: Allocated port 12104 for RTP instance '0x7fe48000b618' [Jun 18 15:46:55] DEBUG[20912] pjsip: icess0x7fe4800 ICE session created, comp_cnt=2, role is Unknown agent [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:55] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 0 added: comp_id=1, type=host, foundation=Ha18127c, addr=10.24.18.124:12104, base=10.24.18.124:12104, prio=0x7effffff (2130706431) [Jun 18 15:46:55] DEBUG[20912] rtp_engine.c: RTP instance '0x7fe48000b618' is setup and ready to go [Jun 18 15:46:55] DEBUG[20912] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fe48000b618' [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:55] DEBUG[20912] pjsip: icess0x7fe4800 Candidate 1 added: comp_id=2, type=host, foundation=Ha18127c, addr=10.24.18.124:12105, base=10.24.18.124:12105, prio=0x7efffffe (2130706430) [Jun 18 15:46:55] DEBUG[20912] pjsip: icess0x7fe4800 Destroying ICE session 0x7fe480020e88 [Jun 18 15:46:55] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe48000f928 destroy request, ref_cnt=4 [Jun 18 15:46:55] DEBUG[20912] pjsip: stuse0x7fe4800 STUN session 0x7fe48002ec08 destroy request, ref_cnt=3 [Jun 18 15:46:55] DEBUG[20912] pjsip: ice_session.c ICE session 0x7fe480020e88 destroyed [Jun 18 15:46:55] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe48000f928 destroyed [Jun 18 15:46:55] DEBUG[20912] pjsip: stun_session.c STUN session 0x7fe48002ec08 destroyed [Jun 18 15:46:55] DEBUG[20912] pjsip: endpoint Request msg INVITE/cseq=30406 (tdta0x7fe430005a00) created. [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module WebSocket Transport Module added as dialog usage, data=(nil) [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 Module NAT added as dialog usage, data=(nil) [Jun 18 15:46:55] DEBUG[20912] pjsip: inv0x7fe430015 .Sending Request msg INVITE/cseq=30406 (tdta0x7fe430005a00) [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ..Sending Request msg INVITE/cseq=30406 (tdta0x7fe430005a00) [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 ...Transaction created for Request msg INVITE/cseq=30405 (tdta0x7fe430005a00) [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 ..Sending Request msg INVITE/cseq=30405 (tdta0x7fe430005a00) in state Null [Jun 18 15:46:55] DEBUG[20912] pjsip: sip_resolve.c ...Target '10.24.20.234:5062' type=Unspecified resolved to '10.24.20.234:5062' type=UDP (UDP transport) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.24.18.124:5060 [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:46:55] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP request (942 bytes) to UDP:10.24.20.234:5062 ---> INVITE sip:CATHY@10.24.20.234:5062 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjaa336157-fb58-4694-b5a0-d53a7d9be3c2 From: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff To: Contact: Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30405 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER, REGISTER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-723a9d4 Content-Type: application/sdp Content-Length: 235 v=0 o=- 532391251 532391251 IN IP4 10.24.18.124 s=Asterisk c=IN IP4 10.24.18.124 t=0 0 m=audio 12104 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Null to Calling, event=TX_MSG [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ....Transaction tsx0x7fe4300329d8 state changed to Calling [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current transaction state is Calling [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Method is INVITE [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 100/INVITE/cseq=30405 (rdata0x7fe44833d648) [Jun 18 15:46:55] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (364 bytes) from UDP:10.24.20.234:5062 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjaa336157-fb58-4694-b5a0-d53a7d9be3c2 From: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff To: Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30405 INVITE User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 100/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 .Incoming Response msg 100/INVITE/cseq=30405 (rdata0x7fe44800e9d8) in state Calling [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 ..State changed from Calling to Proceeding, event=RX_MSG [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ...Received Response msg 100/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ...Transaction tsx0x7fe4300329d8 state changed to Proceeding [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current inv state is CALLING [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Response is 100 Trying [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=30405 (rdata0x7fe44833d648) [Jun 18 15:46:55] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (589 bytes) from UDP:10.24.20.234:5062 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjaa336157-fb58-4694-b5a0-d53a7d9be3c2 From: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff To: ;tag=425875951 Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30405 INVITE Contact: Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE User-Agent: Yealink SIP-T28P 2.61.0.80 Allow-Events: talk,hold,conference,refer,check-sync Content-Length: 0 [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 180/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 .Incoming Response msg 180/INVITE/cseq=30405 (rdata0x7fe44800e9d8) in state Proceeding [Jun 18 15:46:55] DEBUG[20912] pjsip: tsx0x7fe430032 ..State changed from Proceeding to Proceeding, event=RX_MSG [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ...Received Response msg 180/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ....Route-set updated [Jun 18 15:46:55] DEBUG[20912] pjsip: dlg0x7fe430015 ...Transaction tsx0x7fe4300329d8 state changed to Proceeding [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Response is 180 Ringing [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current transaction state is Proceeding [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: The current inv state is EARLY [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:46:55] DEBUG[20912] res_pjsip_session.c: Response is 180 Ringing [Jun 18 15:46:55] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - CATHY [Jun 18 15:46:55] DEBUG[20560] devicestate.c: Changing state for PJSIP/CATHY - state 6 (Ringing) [Jun 18 15:46:55] DEBUG[20618] app_queue.c: Device 'PJSIP/CATHY' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jun 18 15:46:55] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for Local - 103@from-internal [Jun 18 15:46:55] DEBUG[20560] devicestate.c: Changing state for Local/103@from-internal - state 2 (In use) [Jun 18 15:46:55] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - ALICE [Jun 18 15:46:55] DEBUG[20618] app_queue.c: Device 'Local/103@from-internal' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:46:55] DEBUG[20560] devicestate.c: Changing state for PJSIP/ALICE - state 2 (In use) [Jun 18 15:46:55] DEBUG[20921][C-00000003] channel.c: Driver for channel 'PJSIP/ALICE-00000009' does not support indication 3, emulating it [Jun 18 15:46:55] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: slin -> ulaw [Jun 18 15:46:55] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Difference is 8160, ms is 1040 [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:55] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:55] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:46:55] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:55] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:55] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '10.24.18.16:4059' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '10.24.18.16' and port '4059'. [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:46:55] DEBUG[20921][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20921][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:55] DEBUG[20921][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:55] DEBUG[20921][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20921][C-00000003] acl.c: Attached to given IP address [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '10.24.18.16:4059' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '10.24.18.16' and port '4059'. [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:46:55] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:55] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:55] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:55] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:46:55] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:55] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg SUBSCRIBE/cseq=22944 (rdata0x7fe44833d648) [Jun 18 15:46:55] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (655 bytes) from UDP:10.24.18.16:5060 ---> SUBSCRIBE sip:ALICE@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjhNtjsOiGEWHOeHscbESoESkN0sDiaHRb Max-Forwards: 70 From: "Lindsey Freddie" ;tag=XuUlE8UpcPPceqPgBT.bsIvgUKEn9UHJ To: "Lindsey Freddie" Contact: "Lindsey Freddie" Call-ID: C.iPpkK.dc853AkpKD.eJT0iaTcVUJ6J CSeq: 22944 SUBSCRIBE Event: message-summary Expires: 3600 Supported: replaces, 100rel, timer, norefersub Accept: application/simple-message-summary Allow-Events: presence, message-summary, refer User-Agent: Digium D40 1_4_2_0_63880 Content-Length: 0 [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg SUBSCRIBE/cseq=22944 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:46:55] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint ALICE [Jun 18 15:46:55] DEBUG[20912] pjsip: endpoint .Response msg 401/SUBSCRIBE/cseq=22944 (tdta0x7fe4300049f0) created [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:55] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (595 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjhNtjsOiGEWHOeHscbESoESkN0sDiaHRb Call-ID: C.iPpkK.dc853AkpKD.eJT0iaTcVUJ6J From: "Lindsey Freddie" ;tag=XuUlE8UpcPPceqPgBT.bsIvgUKEn9UHJ To: "Lindsey Freddie" ;tag=z9hG4bKPjhNtjsOiGEWHOeHscbESoESkN0sDiaHRb CSeq: 22944 SUBSCRIBE WWW-Authenticate: Digest realm="asterisk",nonce="1434660415/809c434febaf82bf51fb9601fca060f8",opaque="0d956b7c602b8f47",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:55] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 401/SUBSCRIBE/cseq=22944 (tdta0x7fe4300049f0) [Jun 18 15:46:55] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg SUBSCRIBE/cseq=22945 (rdata0x7fe44833d648) [Jun 18 15:46:55] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (954 bytes) from UDP:10.24.18.16:5060 ---> SUBSCRIBE sip:ALICE@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPj5nHfM5kERtPPv0BQgNuWwM37fH1CNNBL Max-Forwards: 70 From: "Lindsey Freddie" ;tag=XuUlE8UpcPPceqPgBT.bsIvgUKEn9UHJ To: "Lindsey Freddie" Contact: "Lindsey Freddie" Call-ID: C.iPpkK.dc853AkpKD.eJT0iaTcVUJ6J CSeq: 22945 SUBSCRIBE Event: message-summary Expires: 3600 Supported: replaces, 100rel, timer, norefersub Accept: application/simple-message-summary Allow-Events: presence, message-summary, refer User-Agent: Digium D40 1_4_2_0_63880 Authorization: Digest username="ALICE", realm="asterisk", nonce="1434660415/809c434febaf82bf51fb9601fca060f8", uri="sip:ALICE@10.24.18.124:5060", response="0e4b0292051195737e3dddf62abc11ae", algorithm=md5, cnonce="8vyYYCuHX84ohP0jbwwvWYS5DIvzK.qj", opaque="0d956b7c602b8f47", qop=auth, nc=00000001 Content-Length: 0 [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:55] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg SUBSCRIBE/cseq=22945 (rdata0x7fe44800e9d8) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:46:55] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint ALICE [Jun 18 15:46:55] DEBUG[20912] pjsip: endpoint .Response msg 401/SUBSCRIBE/cseq=22945 (tdta0x7fe4300049f0) created [Jun 18 15:46:55] DEBUG[20912] res_pjsip_authenticator_digest.c: Calculated nonce 1434660415/809c434febaf82bf51fb9601fca060f8. Actual nonce is 1434660415/809c434febaf82bf51fb9601fca060f8 [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.16' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port ''. [Jun 18 15:46:55] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 401/SUBSCRIBE/cseq=22945 (tdta0x7fe4300049f0) [Jun 18 15:46:55] DEBUG[20912] res_pjsip_pubsub.c: Body generator 0x7fe40a7b6120 found for accept type application/simple-message-summary [Jun 18 15:46:55] DEBUG[20912] res_pjsip_pubsub.c: Subscription to resource ALICE is not to a list [Jun 18 15:46:55] NOTICE[20912] res_pjsip_mwi.c: AOR ALICE has no configured mailboxes. MWI subscription failed [Jun 18 15:46:55] DEBUG[20912] pjsip: endpoint .Response msg 404/SUBSCRIBE/cseq=22945 (tdta0x7fe4300049f0) created [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:55] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:55] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:55] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (445 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPj5nHfM5kERtPPv0BQgNuWwM37fH1CNNBL Call-ID: C.iPpkK.dc853AkpKD.eJT0iaTcVUJ6J From: "Lindsey Freddie" ;tag=XuUlE8UpcPPceqPgBT.bsIvgUKEn9UHJ To: "Lindsey Freddie" ;tag=z9hG4bKPj5nHfM5kERtPPv0BQgNuWwM37fH1CNNBL CSeq: 22945 SUBSCRIBE Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:55] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 404/SUBSCRIBE/cseq=22945 (tdta0x7fe4300049f0) [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:55] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:56] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:57] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:58] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20921][C-00000003] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Jun 18 15:46:59] DEBUG[20921][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:59] DEBUG[20921][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:46:59] DEBUG[20921][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:46:59] DEBUG[20921][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:46:59] DEBUG[20921][C-00000003] acl.c: Attached to given IP address [Jun 18 15:46:59] DEBUG[20608] netsock2.c: Splitting '10.24.18.16:4059' into... [Jun 18 15:46:59] DEBUG[20608] netsock2.c: ...host '10.24.18.16' and port '4059'. [Jun 18 15:46:59] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:46:59] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:46:59] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg BYE/cseq=16640 (rdata0x7fe44833d648) [Jun 18 15:46:59] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (419 bytes) from UDP:10.24.18.16:5060 ---> BYE sip:10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.16:5060;rport;branch=z9hG4bKPjk2m6np9fptQ9ZEmH1i9SULX.ttpwi.Xb Max-Forwards: 70 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=b597b99e-401c-46d5-827b-d0fee3fa9880 Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 CSeq: 16640 BYE User-Agent: Digium D40 1_4_2_0_63880 Content-Length: 0 [Jun 18 15:46:59] DEBUG[20576] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:59] DEBUG[20576] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:59] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:59] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:59] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg BYE/cseq=16640 (rdata0x7fe44800e9d8) [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f .Received Request msg BYE/cseq=16640 (rdata0x7fe44800e9d8) [Jun 18 15:46:59] DEBUG[20912] pjsip: tsx0x7fe430036 ...Transaction created for Request msg BYE/cseq=16640 (rdata0x7fe44800e9d8) [Jun 18 15:46:59] DEBUG[20912] pjsip: tsx0x7fe430036 ..Incoming Request msg BYE/cseq=16640 (rdata0x7fe44800e9d8) in state Null [Jun 18 15:46:59] DEBUG[20912] pjsip: tsx0x7fe430036 ...State changed from Null to Trying, event=RX_MSG [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f ....Transaction tsx0x7fe4300366f8 state changed to Trying [Jun 18 15:46:59] DEBUG[20912] pjsip: endpoint .....Response msg 200/BYE/cseq=16640 (tdta0x7fe4300049f0) created [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f ......Sending Response msg 200/BYE/cseq=16640 (tdta0x7fe4300049f0) [Jun 18 15:46:59] DEBUG[20912] pjsip: tsx0x7fe430036 ......Sending Response msg 200/BYE/cseq=16640 (tdta0x7fe4300049f0) in state Trying [Jun 18 15:46:59] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:46:59] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:46:59] DEBUG[20912] netsock2.c: Splitting '10.24.18.16:5060' into... [Jun 18 15:46:59] DEBUG[20912] netsock2.c: ...host '10.24.18.16' and port '5060'. [Jun 18 15:46:59] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (407 bytes) to UDP:10.24.18.16:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.18.16:5060;rport=5060;received=10.24.18.16;branch=z9hG4bKPjk2m6np9fptQ9ZEmH1i9SULX.ttpwi.Xb Call-ID: yw9RlJTuVlNHlHOGvBgHbbzvtpHuitq9 From: "Lindsey Freddie" ;tag=hQzYh7iTJRMVeiRbjhOWRdxrJCIFbcA0 To: ;tag=b597b99e-401c-46d5-827b-d0fee3fa9880 CSeq: 16640 BYE Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:46:59] DEBUG[20912] pjsip: tsx0x7fe430036 .......State changed from Trying to Completed, event=TX_MSG [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f ........Transaction tsx0x7fe4300366f8 state changed to Completed [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Method is BYE, Response is 200 OK [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'ALICE(PJSIP/ALICE-00000009)' [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Received request [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Method is BYE [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f ......Session count dec to 4 by mod-invite [Jun 18 15:46:59] DEBUG[20921][C-00000003] channel.c: Channel PJSIP/ALICE-00000009 setting write format path: ulaw -> ulaw [Jun 18 15:46:59] DEBUG[20921][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: inv_session 0x7fe4800067a8 has no ast session [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge_basic.c: Transferer on attended transfer 0x7fe4500014a8 hung up [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge_channel.c: Setting 0x7fe450004778(PJSIP/ALICE-00000009) state from:0 to:1 [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: pulling 0x7fe450004778(PJSIP/ALICE-00000009) [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_basic.c: Received stimulus Transferer Hangup on attended transfer 0x7fe4500014a8 [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: 0x7fe450004778(PJSIP/ALICE-00000009) is leaving simple_bridge technology [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_basic.c: Told to enter state Blond Non-Final exit on attended transfer 0x7fe4500014a8 [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_basic.c: About to enter state Blond Non-Final for attended transfer 0x7fe4500014a8 [Jun 18 15:46:59] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - BOB [Jun 18 15:46:59] DEBUG[20560] devicestate.c: Changing state for PJSIP/BOB - state 2 (In use) [Jun 18 15:46:59] DEBUG[20923][C-00000003] channel.c: Channel PJSIP/BOB-0000000a setting write format path: ulaw -> ulaw [Jun 18 15:46:59] DEBUG[20618] app_queue.c: Device 'PJSIP/BOB' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:46:59] DEBUG[20923][C-00000003] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge_native_rtp.c: Bridge 'fe18974d-cf6c-4e06-93e3-5104e70626f2' can not use native RTP bridge as two channels are required [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:59] DEBUG[20561] cdr.c: Finalized CDR for PJSIP/ALICE-00000009 - start 1434660415.108696 answer 1434660415.108697 end 1434660419.719375 dispo ANSWERED [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:59] DEBUG[20921][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 is already using the new technology. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Merging bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 into bridge 6baf220d-0d6e-4184-9561-9347424112a8 [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: pulling 0x7fe45000f958(Local/103@from-internal-00000003;1) [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_channel.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: 0x7fe45000f958(Local/103@from-internal-00000003;1) is leaving simple_bridge technology [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_channel.c: Channel Local/103@from-internal-00000003;1 will survive this bridge; clearing outgoing (dialed) flag [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pushing 0x7fe45000f958(Local/103@from-internal-00000003;1) [Jun 18 15:46:59] DEBUG[20921][C-00000003] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jun 18 15:46:59] DEBUG[20921][C-00000003] pbx.c: Spawn extension (from-internal,102,1) exited non-zero on 'PJSIP/ALICE-00000009' [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20921][C-00000003] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/ALICE-00000009' [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as it was forbidden while getting details [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe45000f958(Local/103@from-internal-00000003;1) is joining simple_bridge technology [Jun 18 15:46:59] DEBUG[20921][C-00000003] channel.c: Hanging up channel 'PJSIP/ALICE-00000009' [Jun 18 15:46:59] DEBUG[20921][C-00000003] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Jun 18 15:46:59] DEBUG[20912] res_pjsip_session.c: Destroying SIP session with endpoint ALICE [Jun 18 15:46:59] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe4800110a8' [Jun 18 15:46:59] DEBUG[20912] rtp_engine.c: Destroyed RTP instance '0x7fe4800110a8' [Jun 18 15:46:59] DEBUG[20912] pjsip: dlg0x7fe43000f .Session count dec to 0 by Session Module [Jun 18 15:46:59] DEBUG[20912] taskprocessor.c: destroying taskprocessor '2f43550e-effb-436e-9216-d50ea128fdb9' [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge_native_rtp.c: Bridge 'fe18974d-cf6c-4e06-93e3-5104e70626f2' can not use native RTP bridge as two channels are required [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 is already using the new technology. [Jun 18 15:46:59] DEBUG[20926][C-00000003] bridge.c: Merged bridge fe18974d-cf6c-4e06-93e3-5104e70626f2 into bridge 6baf220d-0d6e-4184-9561-9347424112a8 [Jun 18 15:46:59] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - BOB [Jun 18 15:46:59] DEBUG[20923][C-00000003] channel.c: Driver for channel 'PJSIP/BOB-0000000a' does not support indication 3, emulating it [Jun 18 15:46:59] DEBUG[20548] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jun 18 15:46:59] DEBUG[20560] devicestate.c: Changing state for PJSIP/BOB - state 2 (In use) [Jun 18 15:46:59] DEBUG[20923][C-00000003] channel.c: Channel PJSIP/BOB-0000000a setting write format path: slin -> ulaw [Jun 18 15:46:59] DEBUG[20923][C-00000003] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:46:59] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:00] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:00] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:00] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:00] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:47:00] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:00] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:00] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:00] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:47:00] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:00] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:00] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:00] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:00] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:00] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:00] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:00] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:00] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:00] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20924][C-00000003] res_rtp_asterisk.c: No remote address on RTP instance '0x7fe48000b618' so dropping frame [Jun 18 15:47:01] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/INVITE/cseq=30405 (rdata0x7fe44833d648) [Jun 18 15:47:01] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (775 bytes) from UDP:10.24.20.234:5062 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjaa336157-fb58-4694-b5a0-d53a7d9be3c2 From: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff To: ;tag=425875951 Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30405 INVITE Contact: Content-Type: application/sdp Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 211 v=0 o=- 20003 20003 IN IP4 10.24.20.234 s=SDP data c=IN IP4 10.24.20.234 t=0 0 m=audio 11786 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=sendrecv a=ptime:20 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 [Jun 18 15:47:01] DEBUG[20576] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:47:01] DEBUG[20576] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:47:01] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:01] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:01] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:47:01] DEBUG[20912] pjsip: tsx0x7fe430032 .Incoming Response msg 200/INVITE/cseq=30405 (rdata0x7fe44800e9d8) in state Proceeding [Jun 18 15:47:01] DEBUG[20912] pjsip: tsx0x7fe430032 ..State changed from Proceeding to Terminated, event=RX_MSG [Jun 18 15:47:01] DEBUG[20912] pjsip: dlg0x7fe430015 ...Received Response msg 200/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:47:01] DEBUG[20912] pjsip: dlg0x7fe430015 ....Route-set updated [Jun 18 15:47:01] DEBUG[20912] pjsip: dlg0x7fe430015 ....Route-set frozen [Jun 18 15:47:01] DEBUG[20912] pjsip: dlg0x7fe430015 ...Transaction tsx0x7fe4300329d8 state changed to Terminated [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The current inv state is CONNECTING [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Response is 200 OK [Jun 18 15:47:01] DEBUG[20912] pjsip: inv0x7fe430015 ....Got SDP answer in Response msg 200/INVITE/cseq=30405 (rdata0x7fe44800e9d8) [Jun 18 15:47:01] DEBUG[20912] pjsip: inv0x7fe430015 ....SDP negotiation done, status=0 [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:47:01] DEBUG[20912] netsock2.c: Splitting '10.24.20.234' into... [Jun 18 15:47:01] DEBUG[20912] netsock2.c: ...host '10.24.20.234' and port ''. [Jun 18 15:47:01] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe48000b618' [Jun 18 15:47:01] DEBUG[20912] rtp_engine.c: Setting payload 0 (0x7fe480009318) based on m type on 0x7fe43f119e90 [Jun 18 15:47:01] DEBUG[20912] rtp_engine.c: Setting payload 101 (0x7fe480009318) based on m type on 0x7fe43f119e90 [Jun 18 15:47:01] DEBUG[20912] rtp_engine.c: Copying payload 0 (0x7fe48000c188) from 0x7fe43f119e90 to 0x7fe48000b7e0 [Jun 18 15:47:01] DEBUG[20912] rtp_engine.c: Copying payload 101 (0x7fe48000c5e8) from 0x7fe43f119e90 to 0x7fe48000b7e0 [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jun 18 15:47:01] DEBUG[20912] pjsip: inv0x7fe430015 ....Received Response msg 200/INVITE/cseq=30405 (rdata0x7fe44800e9d8), sending ACK [Jun 18 15:47:01] DEBUG[20912] pjsip: endpoint ....Request msg ACK/cseq=30405 (tdta0x7fe430039b10) created. [Jun 18 15:47:01] DEBUG[20912] pjsip: dlg0x7fe430015 .....Sending Request msg ACK/cseq=30405 (tdta0x7fe430039b10) [Jun 18 15:47:01] DEBUG[20912] pjsip: sip_resolve.c .....Target '10.24.20.234:5062' type=Unspecified resolved to '10.24.20.234:5062' type=UDP (UDP transport) [Jun 18 15:47:01] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:01] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:01] DEBUG[20912] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:47:01] DEBUG[20912] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:47:01] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP request (416 bytes) to UDP:10.24.20.234:5062 ---> ACK sip:CATHY@10.24.20.234:5062 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPj99d688d4-2463-451e-b03f-46f71183e909 From: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff To: ;tag=425875951 Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30405 ACK Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fe4300329d8) [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Method is ACK [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The current transaction state is Terminated [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:47:01] DEBUG[20912] res_pjsip_session.c: Response is 200 OK [Jun 18 15:47:01] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - CATHY [Jun 18 15:47:01] DEBUG[20560] devicestate.c: Changing state for PJSIP/CATHY - state 2 (In use) [Jun 18 15:47:01] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for Local - 103@from-internal [Jun 18 15:47:01] DEBUG[20924][C-00000003] core_unreal.c: Blocked indication -1 [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_basic.c: Detected an answer for recall attempt on attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20560] devicestate.c: Changing state for Local/103@from-internal - state 2 (In use) [Jun 18 15:47:01] DEBUG[20925][C-00000003] channel.c: Ignoring answer on an inbound call! [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_basic.c: Received stimulus Recall Target Answer on attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_basic.c: Told to enter state Resume exit on attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_basic.c: About to enter state Resume for attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_basic.c: State Resume is a terminal state. Ending attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_basic.c: Shutting down attended transfer 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge_native_rtp.c: Bridge '4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb' can not use native RTP bridge as two channels are required [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as it was forbidden while getting details [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling simple_bridge technology constructor [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling simple_bridge technology start [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c0070d8(Local/103@from-internal-00000003;2) is joining [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c009cf8(PJSIP/CATHY-0000000b) is joining [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pushing 0x7fe41c0070d8(Local/103@from-internal-00000003;2) [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge_native_rtp.c: Bridge '4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb' can not use native RTP bridge as two channels are required [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is already using the new technology. [Jun 18 15:47:01] DEBUG[20924][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c0070d8(Local/103@from-internal-00000003;2) is joining simple_bridge technology [Jun 18 15:47:01] DEBUG[20618] app_queue.c: Device 'PJSIP/CATHY' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:47:01] DEBUG[20618] app_queue.c: Device 'Local/103@from-internal' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pushing 0x7fe41c009cf8(PJSIP/CATHY-0000000b) [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge_native_rtp.c: Bridge '4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb' can not use native RTP bridge as it was forbidden while getting details [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is already using the new technology. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c009cf8(PJSIP/CATHY-0000000b) is joining simple_bridge technology [Jun 18 15:47:01] DEBUG[20561] cdr.c: Finalized CDR for PJSIP/CATHY-0000000b - start 1434660415.108873 answer 1434660421.681338 end 1434660421.682758 dispo ANSWERED [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: telling all channels to leave the party [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: dissolving bridge with cause 16(Normal Clearing) [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: queueing action type:13 sub:1001 [Jun 18 15:47:01] DEBUG[20926][C-00000003] bridge_roles.c: Removing bridge role transferer from channel PJSIP/ALICE-00000009 [Jun 18 15:47:01] DEBUG[20559][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: actually destroying basic bridge, nobody wants it anymore [Jun 18 15:47:01] DEBUG[20559][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: calling basic bridge destructor [Jun 18 15:47:01] DEBUG[20559][C-00000003] bridge_basic.c: Destroy attended transfer properties 0x7fe4500014a8 [Jun 18 15:47:01] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - ALICE [Jun 18 15:47:01] DEBUG[20560] devicestate.c: Changing state for PJSIP/ALICE - state 1 (Not in use) [Jun 18 15:47:01] DEBUG[20559][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: calling simple_bridge technology stop [Jun 18 15:47:01] DEBUG[20559][C-00000003] bridge.c: Bridge fe18974d-cf6c-4e06-93e3-5104e70626f2: calling simple_bridge technology destructor [Jun 18 15:47:01] DEBUG[20618] app_queue.c: Device 'PJSIP/ALICE' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Moving 0x7fe450004608(PJSIP/BOB-0000000a) into bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb swapping with Local/103@from-internal-00000003;2 [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pulling 0x7fe450004608(PJSIP/BOB-0000000a) [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe450004608(PJSIP/BOB-0000000a) is leaving simple_bridge technology [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Channel PJSIP/BOB-0000000a will survive this bridge; clearing outgoing (dialed) flag [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pushing 0x7fe450004608(PJSIP/BOB-0000000a) by swapping with 0x7fe41c0070d8(Local/103@from-internal-00000003;2) [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Setting 0x7fe41c0070d8(Local/103@from-internal-00000003;2) state from:0 to:2 [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pulling 0x7fe41c0070d8(Local/103@from-internal-00000003;2) [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c0070d8(Local/103@from-internal-00000003;2) is leaving simple_bridge technology [Jun 18 15:47:01] DEBUG[20561] cdr.c: Finalized CDR for Local/103@from-internal-00000003;2 - start 1434660415.106462 answer 1434660421.681782 end 1434660421.688824 dispo ANSWERED [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Chose bridge technology native_rtp [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling native_rtp technology constructor [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: moving 0x7fe41c009cf8(PJSIP/CATHY-0000000b) to dummy bridge temporarily [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c009cf8(PJSIP/CATHY-0000000b) is leaving simple_bridge technology (dummy) [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling simple_bridge technology stop [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe450004608(PJSIP/BOB-0000000a) is joining native_rtp technology [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c009cf8(PJSIP/CATHY-0000000b) is joining native_rtp technology [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling native_rtp technology start [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling simple_bridge technology destructor [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_native_rtp.c: Bridge '6baf220d-0d6e-4184-9561-9347424112a8' can not use native RTP bridge as two channels are required [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Chose bridge technology simple_bridge [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is already using the new technology. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Setting 0x7fe45000f958(Local/103@from-internal-00000003;1) state from:0 to:2 [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: pulling 0x7fe45000f958(Local/103@from-internal-00000003;1) [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Chose bridge technology native_rtp [Jun 18 15:47:01] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is already using the new technology. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge_channel.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: 0x7fe45000f958(Local/103@from-internal-00000003;1) is leaving simple_bridge technology [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: dissolving bridge with cause 16(Normal Clearing) [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: queueing action type:13 sub:1001 [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8 is dissolved, not performing smart bridge operation. [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: actually destroying basic bridge, nobody wants it anymore [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: calling basic bridge destructor [Jun 18 15:47:01] DEBUG[20561] cdr.c: Finalized CDR for Local/103@from-internal-00000003;1 - start 1434660419.719796 answer 0.000000 end 1434660421.689905 dispo NO ANSWER [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: calling simple_bridge technology stop [Jun 18 15:47:01] DEBUG[20925][C-00000003] bridge.c: Bridge 6baf220d-0d6e-4184-9561-9347424112a8: calling simple_bridge technology destructor [Jun 18 15:47:01] DEBUG[20925][C-00000003] channel.c: Hanging up channel 'Local/103@from-internal-00000003;1' [Jun 18 15:47:01] DEBUG[20576] pjsip: tsx0x7fe430032 Timeout timer event [Jun 18 15:47:01] DEBUG[20576] pjsip: tsx0x7fe430032 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:47:01] DEBUG[20576] pjsip: tsx0x7fe430032 Transaction destroyed! [Jun 18 15:47:01] DEBUG[20561] cdr.c: CDR for Local/103@from-internal-00000003;1 is dialed and has no Party B; discarding [Jun 18 15:47:01] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for Local - 103@from-internal [Jun 18 15:47:01] DEBUG[20560] devicestate.c: Changing state for Local/103@from-internal - state 1 (Not in use) [Jun 18 15:47:01] DEBUG[20618] app_queue.c: Device 'Local/103@from-internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 18 15:47:01] DEBUG[20923][C-00000003] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20923][C-00000003] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jun 18 15:47:01] DEBUG[20923][C-00000003] bridge.c: Chose bridge technology native_rtp [Jun 18 15:47:01] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is already using the new technology. [Jun 18 15:47:01] DEBUG[20924][C-00000003] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jun 18 15:47:01] DEBUG[20924][C-00000003] pbx.c: Spawn extension (from-internal,103,1) exited non-zero on 'Local/103@from-internal-00000003;2' [Jun 18 15:47:01] DEBUG[20924][C-00000003] channel.c: Soft-Hanging (0x10) up channel 'Local/103@from-internal-00000003;2' [Jun 18 15:47:01] DEBUG[20924][C-00000003] channel.c: Hanging up channel 'Local/103@from-internal-00000003;2' [Jun 18 15:47:01] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for Local - 103@from-internal [Jun 18 15:47:01] DEBUG[20560] core_local.c: Checking if extension 103@from-internal exists (devicestate) [Jun 18 15:47:01] DEBUG[20560] devicestate.c: Changing state for Local/103@from-internal - state 1 (Not in use) [Jun 18 15:47:01] DEBUG[20618] app_queue.c: Device 'Local/103@from-internal' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 18 15:47:01] DEBUG[20928][C-00000003] res_rtp_asterisk.c: 0x7fe480032410 -- Probation learning mode pass with source address 10.24.20.234:11786 [Jun 18 15:47:05] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:05] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:05] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:05] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:05] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:47:05] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:05] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:05] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:05] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:05] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:47:05] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:05] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:05] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:05] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:05] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:05] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:05] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:05] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:05] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:06] DEBUG[20928][C-00000003] res_rtp_asterisk.c: Got RTCP report of 76 bytes [Jun 18 15:47:06] DEBUG[20928][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:06] DEBUG[20928][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:06] DEBUG[20928][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:06] DEBUG[20928][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:06] DEBUG[20928][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:06] DEBUG[20608] netsock2.c: Splitting '10.24.20.234:11787' into... [Jun 18 15:47:06] DEBUG[20608] netsock2.c: ...host '10.24.20.234' and port '11787'. [Jun 18 15:47:06] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:06] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:08] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg SUBSCRIBE/cseq=17351 (rdata0x7fe44833d648) [Jun 18 15:47:08] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (643 bytes) from UDP:10.24.18.138:5060 ---> SUBSCRIBE sip:BOB@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.138:5060;rport;branch=z9hG4bKPjfbWfhm7fLmEl2zFMTi1AuJjTpDi8vLqT Max-Forwards: 70 From: "Temple Morgan" ;tag=Cea3j.YQ0ihR2p9fhxvrPx7DkJ04Cv3G To: "Temple Morgan" Contact: "Temple Morgan" Call-ID: R9wuNNcHMG0z7th9DqwBwcJ29anG-W9I CSeq: 17351 SUBSCRIBE Event: message-summary Expires: 3600 Supported: replaces, 100rel, timer, norefersub Accept: application/simple-message-summary Allow-Events: presence, message-summary, refer User-Agent: Digium D40 1_4_2_0_63880 Content-Length: 0 [Jun 18 15:47:08] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:08] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:08] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:08] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:08] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg SUBSCRIBE/cseq=17351 (rdata0x7fe44800e9d8) [Jun 18 15:47:08] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:47:08] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint BOB [Jun 18 15:47:08] DEBUG[20912] pjsip: endpoint .Response msg 401/SUBSCRIBE/cseq=17351 (tdta0x7fe43000ddb0) created [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.138' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port ''. [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:08] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (589 bytes) to UDP:10.24.18.138:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.18.138:5060;rport=5060;received=10.24.18.138;branch=z9hG4bKPjfbWfhm7fLmEl2zFMTi1AuJjTpDi8vLqT Call-ID: R9wuNNcHMG0z7th9DqwBwcJ29anG-W9I From: "Temple Morgan" ;tag=Cea3j.YQ0ihR2p9fhxvrPx7DkJ04Cv3G To: "Temple Morgan" ;tag=z9hG4bKPjfbWfhm7fLmEl2zFMTi1AuJjTpDi8vLqT CSeq: 17351 SUBSCRIBE WWW-Authenticate: Digest realm="asterisk",nonce="1434660428/9d864d039c47f65681675576fea5ee08",opaque="0f16d70206f0157b",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:47:08] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 401/SUBSCRIBE/cseq=17351 (tdta0x7fe43000ddb0) [Jun 18 15:47:08] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg SUBSCRIBE/cseq=17352 (rdata0x7fe44833d648) [Jun 18 15:47:08] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (938 bytes) from UDP:10.24.18.138:5060 ---> SUBSCRIBE sip:BOB@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.18.138:5060;rport;branch=z9hG4bKPjaj9JFWusrbHbUfDsUfuuY0jMYh-LlkpN Max-Forwards: 70 From: "Temple Morgan" ;tag=Cea3j.YQ0ihR2p9fhxvrPx7DkJ04Cv3G To: "Temple Morgan" Contact: "Temple Morgan" Call-ID: R9wuNNcHMG0z7th9DqwBwcJ29anG-W9I CSeq: 17352 SUBSCRIBE Event: message-summary Expires: 3600 Supported: replaces, 100rel, timer, norefersub Accept: application/simple-message-summary Allow-Events: presence, message-summary, refer User-Agent: Digium D40 1_4_2_0_63880 Authorization: Digest username="BOB", realm="asterisk", nonce="1434660428/9d864d039c47f65681675576fea5ee08", uri="sip:BOB@10.24.18.124:5060", response="f5034cf872422db01961ee9ee0201f76", algorithm=md5, cnonce="jBIsGk4IbSPQ3zkFWfPUa1TSeCpHEfnK", opaque="0f16d70206f0157b", qop=auth, nc=00000001 Content-Length: 0 [Jun 18 15:47:08] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:08] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:08] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:08] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:08] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg SUBSCRIBE/cseq=17352 (rdata0x7fe44800e9d8) [Jun 18 15:47:08] DEBUG[20912] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jun 18 15:47:08] DEBUG[20912] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint BOB [Jun 18 15:47:08] DEBUG[20912] pjsip: endpoint .Response msg 401/SUBSCRIBE/cseq=17352 (tdta0x7fe43000ddb0) created [Jun 18 15:47:08] DEBUG[20912] res_pjsip_authenticator_digest.c: Calculated nonce 1434660428/9d864d039c47f65681675576fea5ee08. Actual nonce is 1434660428/9d864d039c47f65681675576fea5ee08 [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.124' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.124' and port ''. [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.138' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port ''. [Jun 18 15:47:08] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 401/SUBSCRIBE/cseq=17352 (tdta0x7fe43000ddb0) [Jun 18 15:47:08] DEBUG[20912] res_pjsip_pubsub.c: Body generator 0x7fe40a7b6120 found for accept type application/simple-message-summary [Jun 18 15:47:08] DEBUG[20912] res_pjsip_pubsub.c: Subscription to resource BOB is not to a list [Jun 18 15:47:08] NOTICE[20912] res_pjsip_mwi.c: AOR BOB has no configured mailboxes. MWI subscription failed [Jun 18 15:47:08] DEBUG[20912] pjsip: endpoint .Response msg 404/SUBSCRIBE/cseq=17352 (tdta0x7fe43000ddb0) created [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:08] DEBUG[20912] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:08] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:08] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (439 bytes) to UDP:10.24.18.138:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 10.24.18.138:5060;rport=5060;received=10.24.18.138;branch=z9hG4bKPjaj9JFWusrbHbUfDsUfuuY0jMYh-LlkpN Call-ID: R9wuNNcHMG0z7th9DqwBwcJ29anG-W9I From: "Temple Morgan" ;tag=Cea3j.YQ0ihR2p9fhxvrPx7DkJ04Cv3G To: "Temple Morgan" ;tag=z9hG4bKPjaj9JFWusrbHbUfDsUfuuY0jMYh-LlkpN CSeq: 17352 SUBSCRIBE Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:47:08] DEBUG[20912] pjsip: tdta0x7fe43000 .Destroying txdata Response msg 404/SUBSCRIBE/cseq=17352 (tdta0x7fe43000ddb0) [Jun 18 15:47:10] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:10] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:10] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:10] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:10] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:47:10] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:10] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:10] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:10] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:10] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:47:10] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:10] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:10] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:10] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:10] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:10] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:10] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:10] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:10] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:13] DEBUG[20928][C-00000003] res_rtp_asterisk.c: Got RTCP report of 76 bytes [Jun 18 15:47:13] DEBUG[20928][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:13] DEBUG[20928][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:13] DEBUG[20928][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:13] DEBUG[20928][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:13] DEBUG[20928][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:13] DEBUG[20608] netsock2.c: Splitting '10.24.20.234:11787' into... [Jun 18 15:47:13] DEBUG[20608] netsock2.c: ...host '10.24.20.234' and port '11787'. [Jun 18 15:47:13] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:13] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:15] DEBUG[20914] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:15] DEBUG[20915] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:15] DEBUG[20570] threadpool.c: Destroying worker thread 156 [Jun 18 15:47:15] DEBUG[20570] threadpool.c: Destroying worker thread 157 [Jun 18 15:47:15] DEBUG[20916] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:15] DEBUG[20570] threadpool.c: Destroying worker thread 158 [Jun 18 15:47:15] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:15] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:15] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:15] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:15] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:47:15] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:15] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:15] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:15] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:15] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:47:15] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:15] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:15] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:15] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:15] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:15] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:15] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:15] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:15] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:19] DEBUG[20927] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:19] DEBUG[20548] threadpool.c: Destroying worker thread 162 [Jun 18 15:47:20] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:20] DEBUG[20588] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:20] DEBUG[20588] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:20] DEBUG[20588] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:20] DEBUG[20588] acl.c: Attached to given IP address [Jun 18 15:47:20] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:20] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:20] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:20] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:20] DEBUG[20923][C-00000003] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jun 18 15:47:20] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:20] DEBUG[20923][C-00000003] netsock2.c: Splitting 'newtonr-laptop' into... [Jun 18 15:47:20] DEBUG[20923][C-00000003] netsock2.c: ...host 'newtonr-laptop' and port ''. [Jun 18 15:47:20] DEBUG[20923][C-00000003] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jun 18 15:47:20] DEBUG[20923][C-00000003] acl.c: Attached to given IP address [Jun 18 15:47:20] DEBUG[20608] netsock2.c: Splitting '10.24.18.138:4025' into... [Jun 18 15:47:20] DEBUG[20608] netsock2.c: ...host '10.24.18.138' and port '4025'. [Jun 18 15:47:20] DEBUG[20608] netsock2.c: Splitting '127.0.1.1:0' into... [Jun 18 15:47:20] DEBUG[20608] netsock2.c: ...host '127.0.1.1' and port '0'. [Jun 18 15:47:21] DEBUG[20917] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:21] DEBUG[20547] threadpool.c: Destroying worker thread 159 [Jun 18 15:47:21] DEBUG[20922] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:21] DEBUG[20920] threadpool.c: Worker thread idle timeout reached. Dying. [Jun 18 15:47:21] DEBUG[20548] threadpool.c: Destroying worker thread 161 [Jun 18 15:47:21] DEBUG[20548] threadpool.c: Destroying worker thread 160 [Jun 18 15:47:25] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Request msg BYE/cseq=30406 (rdata0x7fe44833d648) [Jun 18 15:47:25] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP request (450 bytes) from UDP:10.24.20.234:5062 ---> BYE sip:a8c1c4f7-b9c6-4211-a119-fd4a70fd1982@10.24.18.124:5060 SIP/2.0 Via: SIP/2.0/UDP 10.24.20.234:5062;branch=z9hG4bK435588738 From: ;tag=425875951 To: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 CSeq: 30406 BYE Contact: Max-Forwards: 70 User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Jun 18 15:47:25] DEBUG[20576] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:47:25] DEBUG[20576] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:47:25] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:25] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:25] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg BYE/cseq=30406 (rdata0x7fe44800e9d8) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 .Received Request msg BYE/cseq=30406 (rdata0x7fe44800e9d8) [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430032 ...Transaction created for Request msg BYE/cseq=30406 (rdata0x7fe44800e9d8) [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430032 ..Incoming Request msg BYE/cseq=30406 (rdata0x7fe44800e9d8) in state Null [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430032 ...State changed from Null to Trying, event=RX_MSG [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 ....Transaction tsx0x7fe4300329d8 state changed to Trying [Jun 18 15:47:25] DEBUG[20912] pjsip: endpoint .....Response msg 200/BYE/cseq=30406 (tdta0x7fe43000ddb0) created [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 ......Sending Response msg 200/BYE/cseq=30406 (tdta0x7fe43000ddb0) [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430032 ......Sending Response msg 200/BYE/cseq=30406 (tdta0x7fe43000ddb0) in state Trying [Jun 18 15:47:25] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:25] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:25] DEBUG[20912] netsock2.c: Splitting '10.24.20.234:5062' into... [Jun 18 15:47:25] DEBUG[20912] netsock2.c: ...host '10.24.20.234' and port '5062'. [Jun 18 15:47:25] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP response (367 bytes) to UDP:10.24.20.234:5062 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.20.234:5062;rport=5062;received=10.24.20.234;branch=z9hG4bK435588738 Call-ID: f8f2a93f-af6f-4402-aa11-83d3bdd94d81 From: ;tag=425875951 To: "Lindsey Freddie" ;tag=8e969a58-37d0-4c89-b6e5-ab1f373c63ff CSeq: 30406 BYE Server: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430032 .......State changed from Trying to Completed, event=TX_MSG [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 ........Transaction tsx0x7fe4300329d8 state changed to Completed [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Sending response [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Method is BYE, Response is 200 OK [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'CATHY(PJSIP/CATHY-0000000b)' [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Received request [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Method is BYE [Jun 18 15:47:25] DEBUG[20912] pjsip: tdta0x7fe43003 .....Destroying txdata Request msg ACK/cseq=30405 (tdta0x7fe430039b10) [Jun 18 15:47:25] DEBUG[20912] pjsip: tdta0x7fe43000 .....Destroying txdata Request msg INVITE/cseq=30405 (tdta0x7fe430005a00) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 ......Session count dec to 4 by mod-invite [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: inv_session 0x7fe48002dce8 has no ast session [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fe4300329d8 [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:25] DEBUG[20548] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge_channel.c: Setting 0x7fe41c009cf8(PJSIP/CATHY-0000000b) state from:0 to:1 [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pulling 0x7fe41c009cf8(PJSIP/CATHY-0000000b) [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe41c009cf8(PJSIP/CATHY-0000000b) is leaving native_rtp technology [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge_native_rtp.c: Discontinued RTP bridging of 'PJSIP/BOB-0000000a' and 'PJSIP/CATHY-0000000b' - media will flow through Asterisk core [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: dissolving bridge with cause 16(Normal Clearing) [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge_channel.c: Setting 0x7fe450004608(PJSIP/BOB-0000000a) state from:0 to:2 [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: queueing action type:13 sub:1001 [Jun 18 15:47:25] DEBUG[20928][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is dissolved, not performing smart bridge operation. [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: pulling 0x7fe450004608(PJSIP/BOB-0000000a) [Jun 18 15:47:25] DEBUG[20928][C-00000003] channel.c: Hanging up channel 'PJSIP/CATHY-0000000b' [Jun 18 15:47:25] DEBUG[20928][C-00000003] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge_channel.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: 0x7fe450004608(PJSIP/BOB-0000000a) is leaving native_rtp technology [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb is dissolved, not performing smart bridge operation. [Jun 18 15:47:25] DEBUG[20561] cdr.c: Finalized CDR for PJSIP/BOB-0000000a - start 1434660421.689008 answer 1434660421.689009 end 1434660445.115212 dispo ANSWERED [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge_channel.c: Bridge is returning 0x7fe450004608(PJSIP/BOB-0000000a) to write format ulaw [Jun 18 15:47:25] DEBUG[20923][C-00000003] channel.c: Channel PJSIP/BOB-0000000a setting write format path: ulaw -> ulaw [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: actually destroying basic bridge, nobody wants it anymore [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Destroying SIP session with endpoint CATHY [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling basic bridge destructor [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling native_rtp technology stop [Jun 18 15:47:25] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe48000b618' [Jun 18 15:47:25] DEBUG[20923][C-00000003] bridge.c: Bridge 4d1c3ebe-75ec-4b20-8af9-abfca5ebedeb: calling native_rtp technology destructor [Jun 18 15:47:25] DEBUG[20912] rtp_engine.c: Destroyed RTP instance '0x7fe48000b618' [Jun 18 15:47:25] DEBUG[20923][C-00000003] channel.c: Hanging up channel 'PJSIP/BOB-0000000a' [Jun 18 15:47:25] DEBUG[20923][C-00000003] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430015 .Session count dec to 0 by Session Module [Jun 18 15:47:25] DEBUG[20561] cdr.c: CDR for PJSIP/CATHY-0000000b is dialed and has no Party B; discarding [Jun 18 15:47:25] DEBUG[20912] taskprocessor.c: destroying taskprocessor 'a947d777-8221-484b-9b41-2158b0603804' [Jun 18 15:47:25] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - CATHY [Jun 18 15:47:25] DEBUG[20912] pjsip: endpoint .Request msg BYE/cseq=9527 (tdta0x7fe4483e92a0) created. [Jun 18 15:47:25] DEBUG[20560] devicestate.c: Changing state for PJSIP/CATHY - state 1 (Not in use) [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Method is BYE [Jun 18 15:47:25] DEBUG[20912] pjsip: inv0x7fe430019 .Sending Request msg BYE/cseq=9527 (tdta0x7fe4483e92a0) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 ..Sending Request msg BYE/cseq=9527 (tdta0x7fe4483e92a0) [Jun 18 15:47:25] DEBUG[20618] app_queue.c: Device 'PJSIP/CATHY' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430019 ...Transaction created for Request msg BYE/cseq=9526 (tdta0x7fe4483e92a0) [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430019 ..Sending Request msg BYE/cseq=9526 (tdta0x7fe4483e92a0) in state Null [Jun 18 15:47:25] DEBUG[20912] pjsip: sip_resolve.c ...Target '10.24.18.138:5060' type=Unspecified resolved to '10.24.18.138:5060' type=UDP (UDP transport) [Jun 18 15:47:25] DEBUG[20912] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:25] DEBUG[20912] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:25] DEBUG[20912] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:25] DEBUG[20912] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:25] VERBOSE[20912] res_pjsip_logger.c: <--- Transmitting SIP request (464 bytes) to UDP:10.24.18.138:5060 ---> BYE sip:BOB@10.24.18.138:5060;ob SIP/2.0 Via: SIP/2.0/UDP 10.24.18.124:5060;rport;branch=z9hG4bKPjc6b3f8b6-b77a-4637-b4a0-176a49ff239a From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: ;tag=HWywDY8Dof4N36poqS-zSbqEhc-XOs3O Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 CSeq: 9526 BYE Reason: Q.850;cause=16 Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-723a9d4 Content-Length: 0 [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430019 ...State changed from Null to Calling, event=TX_MSG [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 ....Transaction tsx0x7fe430019a38 state changed to Calling [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB(PJSIP/BOB-0000000a)' [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fe430019a38 [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current transaction state is Calling [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The transaction state change event is TX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is CONFIRMED [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Sending request [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Method is BYE [Jun 18 15:47:25] DEBUG[20561] cdr.c: CDR for PJSIP/BOB-0000000a is dialed and has no Party B; discarding [Jun 18 15:47:25] DEBUG[20560] devicestate.c: No provider found, checking channel drivers for PJSIP - BOB [Jun 18 15:47:25] DEBUG[20560] devicestate.c: Changing state for PJSIP/BOB - state 1 (Not in use) [Jun 18 15:47:25] DEBUG[20618] app_queue.c: Device 'PJSIP/BOB' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 18 15:47:25] DEBUG[20576] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=9526 (rdata0x7fe44833d648) [Jun 18 15:47:25] VERBOSE[20576] res_pjsip_logger.c: <--- Received SIP response (382 bytes) from UDP:10.24.18.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.18.124:5060;rport=5060;received=10.24.18.124;branch=z9hG4bKPjc6b3f8b6-b77a-4637-b4a0-176a49ff239a Call-ID: 32c02add-d352-4bae-a78c-e42215f048b3 From: "Lindsey Freddie" ;tag=ef368297-4246-430c-a6fd-8cf76ef0a0ad To: ;tag=HWywDY8Dof4N36poqS-zSbqEhc-XOs3O CSeq: 9526 BYE Content-Length: 0 [Jun 18 15:47:25] DEBUG[20576] netsock2.c: Splitting '10.24.18.138:5060' into... [Jun 18 15:47:25] DEBUG[20576] netsock2.c: ...host '10.24.18.138' and port '5060'. [Jun 18 15:47:25] DEBUG[20576] netsock2.c: Splitting '0.0.0.0:5060' into... [Jun 18 15:47:25] DEBUG[20576] netsock2.c: ...host '0.0.0.0' and port '5060'. [Jun 18 15:47:25] DEBUG[20912] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/BYE/cseq=9526 (rdata0x7fe44800e9d8) [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430019 .Incoming Response msg 200/BYE/cseq=9526 (rdata0x7fe44800e9d8) in state Calling [Jun 18 15:47:25] DEBUG[20912] pjsip: tsx0x7fe430019 ..State changed from Calling to Completed, event=RX_MSG [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 ...Received Response msg 200/BYE/cseq=9526 (rdata0x7fe44800e9d8) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 ...Transaction tsx0x7fe430019a38 state changed to Completed [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The state change pertains to the endpoint 'BOB()' [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: There is no transaction involved in this state change [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Received response [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Response is 200 OK [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Destroying SIP session with endpoint BOB [Jun 18 15:47:25] DEBUG[20912] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fe480017488' [Jun 18 15:47:25] DEBUG[20912] rtp_engine.c: Destroyed RTP instance '0x7fe480017488' [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 .....Session count dec to 2 by Session Module [Jun 18 15:47:25] DEBUG[20912] pjsip: tdta0x7fe43001 ....Destroying txdata Request msg ACK/cseq=9525 (tdta0x7fe430013410) [Jun 18 15:47:25] DEBUG[20912] pjsip: tdta0x7fe43003 ....Destroying txdata Request msg INVITE/cseq=9525 (tdta0x7fe43003ab20) [Jun 18 15:47:25] DEBUG[20912] pjsip: dlg0x7fe430019 .....Session count dec to 1 by mod-invite [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: inv_session 0x7fe48001a7b8 has no ast session [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fe430019a38 [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current transaction state is Completed [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The transaction state change event is RX_MSG [Jun 18 15:47:25] DEBUG[20912] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:25] DEBUG[20912] taskprocessor.c: destroying taskprocessor 'f4728c11-7b9b-4b36-8bd1-50f560f05c89' [Jun 18 15:47:30] DEBUG[20576] pjsip: tsx0x7fe430019 Timeout timer event [Jun 18 15:47:30] DEBUG[20576] pjsip: tsx0x7fe430019 .State changed from Completed to Terminated, event=TIMER [Jun 18 15:47:30] DEBUG[20576] pjsip: dlg0x7fe430019 ..Transaction tsx0x7fe430019a38 state changed to Terminated [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: inv_session 0x7fe48001a7b8 has no ast session [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fe430019a38 [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: The current transaction state is Terminated [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: The transaction state change event is TIMER [Jun 18 15:47:30] DEBUG[20576] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:30] DEBUG[20576] pjsip: dlg0x7fe430019 ...Dialog destroyed [Jun 18 15:47:30] DEBUG[20576] pjsip: tsx0x7fe430019 Timeout timer event [Jun 18 15:47:30] DEBUG[20576] pjsip: tsx0x7fe430019 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:47:30] DEBUG[20576] pjsip: tdta0x7fe4483e ..Destroying txdata Request msg BYE/cseq=9526 (tdta0x7fe4483e92a0) [Jun 18 15:47:30] DEBUG[20576] pjsip: tsx0x7fe430019 Transaction destroyed! [Jun 18 15:47:31] DEBUG[20576] pjsip: tsx0x7fe430036 Timeout timer event [Jun 18 15:47:31] DEBUG[20576] pjsip: tsx0x7fe430036 .State changed from Completed to Terminated, event=TIMER [Jun 18 15:47:31] DEBUG[20576] pjsip: dlg0x7fe43000f ..Transaction tsx0x7fe4300366f8 state changed to Terminated [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: inv_session 0x7fe4800067a8 has no ast session [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fe4300366f8 [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: The current transaction state is Terminated [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: The transaction state change event is TIMER [Jun 18 15:47:31] DEBUG[20576] res_pjsip_session.c: The current inv state is DISCONNCTD [Jun 18 15:47:31] DEBUG[20576] pjsip: dlg0x7fe43000f ...Dialog destroyed [Jun 18 15:47:31] DEBUG[20576] pjsip: tsx0x7fe430036 Timeout timer event [Jun 18 15:47:31] DEBUG[20576] pjsip: tsx0x7fe430036 .State changed from Terminated to Destroyed, event=TIMER [Jun 18 15:47:31] DEBUG[20576] pjsip: tdta0x7fe43000 ..Destroying txdata Response msg 200/BYE/cseq=16640 (tdta0x7fe4300049f0) [Jun 18 15:47:31] DEBUG[20576] pjsip: tsx0x7fe430036 Transaction destroyed! [Jun 18 15:47:41] DEBUG[20622] cdr.c: CDR Engine termination request received; waiting on messages... [Jun 18 15:47:41] DEBUG[20622] taskprocessor.c: destroying taskprocessor 'ast_msg_queue' [Jun 18 15:47:41] VERBOSE[20622] asterisk.c: Asterisk cleanly ending (0). [Jun 18 15:47:41] VERBOSE[20622] asterisk.c: Executing last minute cleanups [Jun 18 15:47:41] DEBUG[20622] res_musiconhold.c: Destroying MOH class 'default' [Jun 18 15:47:41] DEBUG[20561] taskprocessor.c: destroying taskprocessor 'dc29afce-3e55-459e-bfdd-29f9ed4b7b19' [Jun 18 15:47:41] DEBUG[20622] asterisk.c: Asterisk ending (0).