[Sep 29 07:14:23] VERBOSE[1200][C-00000000] pbx.c: Executing [pexip@sipit:1] NoOp("Local/pexip@sipit-00000000;2", "") in new stack
[Sep 29 07:14:23] DEBUG[1200][C-00000000] pbx.c: Launching 'Dial'
[Sep 29 07:14:23] VERBOSE[1200][C-00000000] pbx.c: Executing [pexip@sipit:2] Dial("Local/pexip@sipit-00000000;2", "PJSIP/meet.alan") in new stack
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc UAC dialog created
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc Module Outbound Authentica added as dialog usage, data=0xb6a0f88c
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc Module mod-invite added as dialog usage, data=0xb6a0fe4c
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc .Session count inc to 2 by mod-invite
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc Module mod-100rel added as dialog usage, data=0xb6a0ff48
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc 100rel module attached
[Sep 29 07:14:23] DEBUG[1121] pjsip:     inv0xb6a0e7bc UAC invite session created for dialog dlg0xb6a0e7bc
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc .Session count inc to 2 by Session Module
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc Module Session Module added as dialog usage, data=(nil)
[Sep 29 07:14:23] DEBUG[1200][C-00000000] rtp_engine.c: Can't find native functions for channel 'Local/pexip@sipit-00000000;2'
[Sep 29 07:14:23] DEBUG[1121] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb6a14dec'
[Sep 29 07:14:23] DEBUG[1121] res_rtp_asterisk.c: Allocated port 23604 for RTP instance '0xb6a14dec'
[Sep 29 07:14:23] VERBOSE[1200][C-00000000] app_dial.c: Called PJSIP/meet.alan
[Sep 29 07:14:23] DEBUG[1200][C-00000000] channel.c: Set channel PJSIP/meet.alan-00000000 to read format slin
[Sep 29 07:14:23] DEBUG[1200][C-00000000] channel.c: Set channel PJSIP/meet.alan-00000000 to write format slin
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a189c ICE session created, comp_cnt=2, role is Unknown agent
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: Splitting '132.177.253.27' into...
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: ...host '132.177.253.27' and port ''.
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a189c Candidate 0 added: comp_id=1, type=host, foundation=H84b1fd1b, addr=132.177.253.27:23604, base=132.177.253.27:23604, prio=0x7effffff (2130706431)
[Sep 29 07:14:23] DEBUG[1121] rtp_engine.c: RTP instance '0xb6a14dec' is setup and ready to go
[Sep 29 07:14:23] DEBUG[1121] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb6a14dec'
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: Splitting '132.177.253.27' into...
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: ...host '132.177.253.27' and port ''.
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a189c Candidate 1 added: comp_id=2, type=host, foundation=H84b1fd1b, addr=132.177.253.27:23605, base=132.177.253.27:23605, prio=0x7efffffe (2130706430)
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a189c Destroying ICE session 0xb6a189c4
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stuse0xb6a1a3c STUN session 0xb6a1a7dc destroy request, ref_cnt=4
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stuse0xb6a1b3a STUN session 0xb6a1b7c4 destroy request, ref_cnt=3
[Sep 29 07:14:23] DEBUG[1121] pjsip:     ice_session.c ICE session 0xb6a189c4 destroyed
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stun_session.c STUN session 0xb6a1a7dc destroyed
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stun_session.c STUN session 0xb6a1b7c4 destroyed
[Sep 29 07:14:23] DEBUG[1121] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb6a19884'
[Sep 29 07:14:23] DEBUG[1121] res_rtp_asterisk.c: Allocated port 20000 for RTP instance '0xb6a19884'
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a235f ICE session created, comp_cnt=2, role is Unknown agent
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: Splitting '132.177.253.27' into...
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: ...host '132.177.253.27' and port ''.
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a235f Candidate 0 added: comp_id=1, type=host, foundation=H84b1fd1b, addr=132.177.253.27:20000, base=132.177.253.27:20000, prio=0x7effffff (2130706431)
[Sep 29 07:14:23] DEBUG[1121] rtp_engine.c: RTP instance '0xb6a19884' is setup and ready to go
[Sep 29 07:14:23] DEBUG[1121] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb6a19884'
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: Splitting '132.177.253.27' into...
[Sep 29 07:14:23] DEBUG[1121] netsock2.c: ...host '132.177.253.27' and port ''.
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a235f Candidate 1 added: comp_id=2, type=host, foundation=H84b1fd1b, addr=132.177.253.27:20001, base=132.177.253.27:20001, prio=0x7efffffe (2130706430)
[Sep 29 07:14:23] DEBUG[1121] pjsip:    icess0xb6a235f Destroying ICE session 0xb6a235f4
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stuse0xb6a1b65 STUN session 0xb6a1ba74 destroy request, ref_cnt=4
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stuse0xb6a251f STUN session 0xb6a2560c destroy request, ref_cnt=3
[Sep 29 07:14:23] DEBUG[1121] pjsip:     ice_session.c ICE session 0xb6a235f4 destroyed
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stun_session.c STUN session 0xb6a1ba74 destroyed
[Sep 29 07:14:23] DEBUG[1121] pjsip:    stun_session.c STUN session 0xb6a2560c destroyed
[Sep 29 07:14:23] DEBUG[1121] pjsip:          endpoint Request msg INVITE/cseq=22977 (tdta0xb6a05c18) created.
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Method is INVITE
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc Module NAT added as dialog usage, data=(nil)
[Sep 29 07:14:23] DEBUG[1121] pjsip:     inv0xb6a0e7bc .Sending Request msg INVITE/cseq=22977 (tdta0xb6a05c18)
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc ..Sending Request msg INVITE/cseq=22977 (tdta0xb6a05c18)
[Sep 29 07:14:23] DEBUG[1121] pjsip:     tsx0xb6a2c854 ...Transaction created for Request msg INVITE/cseq=22976 (tdta0xb6a05c18)
[Sep 29 07:14:23] DEBUG[1121] pjsip:     tsx0xb6a2c854 ..Sending Request msg INVITE/cseq=22976 (tdta0xb6a05c18) in state Null
[Sep 29 07:14:23] DEBUG[1121] pjsip:     sip_resolve.c ...Starting async DNS SRV query: target=_sip._udp.foo.bar.sipit.net, transport=Unspecified, port=0
[Sep 29 07:14:23] DEBUG[1121] pjsip:    _sip._udp.alan ...Starting async DNS SRV query_job: target=_sip._udp.foo.bar.sipit.net:5060
[Sep 29 07:14:23] DEBUG[1121] pjsip:        resolver.c ...Nameserver 127.0.1.1:53 state changed Active --> Probing
[Sep 29 07:14:23] DEBUG[1121] pjsip:        resolver.c ...Transmitting 48 bytes to NS 0 (127.0.1.1:53): DNS SRV query for _sip._udp.foo.bar.sipit.net: Success
[Sep 29 07:14:23] DEBUG[1121] pjsip:     tsx0xb6a2c854 ...State changed from Null to Calling, event=TX_MSG
[Sep 29 07:14:23] DEBUG[1121] pjsip:     dlg0xb6a0e7bc ....Transaction tsx0xb6a2c854 state changed to Calling
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The state change pertains to the session with meet.alan
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The inv session still has an invite_tsx (0xb6a2c854)
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: There is no transaction involved in this state change
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The current inv state is CALLING
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Source of transaction state change is TX_MSG
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Sending request
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Method is INVITE
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The state change pertains to the session with meet.alan
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The inv session still has an invite_tsx (0xb6a2c854)
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The transaction involved in this state change is 0xb6a2c854
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The current transaction state is Calling
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The transaction state change event is TX_MSG
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: The current inv state is CALLING
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Sending request
[Sep 29 07:14:23] DEBUG[1121] res_pjsip_session.c: Method is INVITE
[Sep 29 07:14:23] DEBUG[1126] pjsip:        resolver.c Received 251 bytes DNS response from 127.0.1.1:53
[Sep 29 07:14:23] DEBUG[1126] pjsip:        resolver.c Nameserver 127.0.1.1:53 state changed Probing --> Active
[Sep 29 07:14:23] DEBUG[1126] pjsip:    _sip._udp.alan SRV query_job for _sip._udp.foo.bar.sipit.net completed, 2 of 2 total entries selected:
[Sep 29 07:14:23] DEBUG[1126] pjsip:    _sip._udp.alan  0: SRV 0 50 5060 foo2.bar.sipit.net (132.177.253.38)
[Sep 29 07:14:23] DEBUG[1126] pjsip:    _sip._udp.alan  1: SRV 0 50 5060 foo1.bar.sipit.net (132.177.253.37)
[Sep 29 07:14:23] DEBUG[1126] pjsip:    _sip._udp.alan Server resolution complete, 2 server entry(s) found
[Sep 29 07:14:23] WARNING[1126] pjsip:   tsx0xb6a2c854 Temporary failure in sending Request msg INVITE/cseq=22976 (tdta0xb6a05c18), will try next server: Unsuitable transport selected (PJSIP_ETPNOTSUITABLE)
[Sep 29 07:14:23] WARNING[1126] pjsip:   tsx0xb6a2c854 Failed to send Request msg INVITE/cseq=22976 (tdta0xb6a05c18)! err=171064 (Unsuitable transport selected (PJSIP_ETPNOTSUITABLE))
[Sep 29 07:14:23] DEBUG[1126] pjsip:     tsx0xb6a2c854 State changed from Calling to Terminated, event=TRANSPORT_ERROR
[Sep 29 07:14:23] DEBUG[1126] pjsip:     dlg0xb6a0e7bc .Transaction tsx0xb6a2c854 state changed to Terminated
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The state change pertains to the session with meet.alan
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The inv session still has an invite_tsx (0xb6a2c854)
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: There is no transaction involved in this state change
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The current inv state is DISCONNCTD
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: Source of transaction state change is TRANSPORT_ERROR
[Sep 29 07:14:23] DEBUG[1126] pjsip:     dlg0xb6a0e7bc ...Session count dec to 2 by mod-invite
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: inv_session 0xb6a0fe4c has no ast session
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The inv session does NOT have an invite_tsx
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The transaction involved in this state change is 0xb6a2c854
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The current transaction state is Terminated
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The transaction state change event is TRANSPORT_ERROR
[Sep 29 07:14:23] DEBUG[1126] res_pjsip_session.c: The current inv state is DISCONNCTD
[Sep 29 07:14:23] DEBUG[1126] pjsip:     tsx0xb6a2c854 Timeout timer event
[Sep 29 07:14:23] DEBUG[1126] pjsip:     tsx0xb6a2c854 .State changed from Terminated to Destroyed, event=TIMER
[Sep 29 07:14:23] DEBUG[1126] pjsip:    tdta0xb6a05c18 ..Destroying txdata Request msg INVITE/cseq=22976 (tdta0xb6a05c18)
[Sep 29 07:14:23] DEBUG[1126] pjsip:     tsx0xb6a2c854 Transaction destroyed!