Outbound problems Freepbx via Vega50 BRI

I have the following issue.

Inbound calls work, audio is fine but I do have an issue with the IVR not getting receiving options from the caller. Although this is not the issue I need help with, just adding incase it is related to my main problem.

1st problem when dialing out all calls start with around 8 seconds of silence between the number being dialled and the ringing tone being played. This happens every time.

2nd problem about 2 in every 10 calls will have one of the following problems, either the ringing noise continues to play on the callers handset after the other side have answered the call, or there is no ringing noise the call connects and both ends just hear silence. With the dialling user not knowing the call has even connected. The handset still shows “Calling” on the display.

The freepbx server is connected to a Vega50 BRI box, all devices involved are on the same subnet, not NAT or firewalls to deal with.

Below is the asterisk output for 2 calls, if that helps. The log on the Vega always shows the same information regardless of what happens call wise. It appears as though the Freepbx is ignoring the call progress from the Vega. I can produce any other logs required.

This call connected but there was only silence

  	[11:11:32] DEBUG[52092][C-0000003c]: pbx.c:2825 pbx_extension_helper: Launching 'Dial'
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:30219 sip_request_call: Asked to create a SIP channel with formats: (ulaw)
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected][::1]:5060 - INVITE (No RTP)
[11:11:32] DEBUG[52092][C-0000003c]: rtp_engine.c:435 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7effa718d328'
[11:11:32] DEBUG[52092][C-0000003c]: res_rtp_asterisk.c:2585 ast_rtp_new: Allocated port 14316 for RTP instance '0x7effa718d328'
[11:11:32] DEBUG[52092][C-0000003c]: rtp_engine.c:444 ast_rtp_instance_new: RTP instance '0x7effa718d328' is setup and ready to go
[11:11:32] DEBUG[52092][C-0000003c]: res_rtp_asterisk.c:4825 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7effa718d328'
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:5781 do_setnat: Setting NAT on RTP to On
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:5781 do_setnat: Setting NAT on RTP to On
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:8736 change_callid_pvt: SIP call-id changed from '[email protected][::1]:5060' to '[email protected]:5060'
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable NODEST from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __MON_FMT from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __FROMEXTEN from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __TIMESTR from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __YEAR from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __MONTH from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __DAY from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __REC_STATUS from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __DIAL_OPTIONS from SIP/334-00000054 to SIP/outbound-vega-00000055.
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:6421 sip_call: Outgoing Call for 071111111
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:13390 add_sdp: ** Our capability: (ulaw) Video flag: False Text flag: False
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:13391 add_sdp: ** Our prefcodec: (ulaw)
[11:11:32] DEBUG[52092][C-0000003c]: chan_sip.c:3387 initialize_initreq: Initializing initreq for method INVITE - callid [email protected]:5060
[11:11:32] DEBUG[27861][C-0000003c]: chan_sip.c:4572 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '[email protected]:5060' Request 102: Found
[11:11:32] DEBUG[45212]: manager.c:6169 process_message: Running action 'Command'
[11:11:37] DEBUG[27861]: rtp_engine.c:378 instance_destructor: Destroyed RTP instance '0x7eff7cd083d8'
[11:11:38] DEBUG[45212]: manager.c:6169 process_message: Running action 'Ping'
[11:11:52] DEBUG[52057]: threadpool.c:1135 worker_idle: Worker thread idle timeout reached. Dying.
[11:11:52] DEBUG[51922]: threadpool.c:1135 worker_idle: Worker thread idle timeout reached. Dying.
[11:11:58] DEBUG[45212]: manager.c:6169 process_message: Running action 'Ping'

This call continued to ring for the caller even after it had been answered

  	[11:23:05] DEBUG[53219][C-00000040]: pbx.c:2825 pbx_extension_helper: Launching 'Dial'
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:30219 sip_request_call: Asked to create a SIP channel with formats: (ulaw)
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected][::1]:5060 - INVITE (No RTP)
[11:23:05] DEBUG[53219][C-00000040]: rtp_engine.c:435 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7effa6691e48'
[11:23:05] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:2585 ast_rtp_new: Allocated port 17984 for RTP instance '0x7effa6691e48'
[11:23:05] DEBUG[53219][C-00000040]: rtp_engine.c:444 ast_rtp_instance_new: RTP instance '0x7effa6691e48' is setup and ready to go
[11:23:05] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4825 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7effa6691e48'
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:5781 do_setnat: Setting NAT on RTP to On
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:5781 do_setnat: Setting NAT on RTP to On
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:8736 change_callid_pvt: SIP call-id changed from '[email protected][::1]:5060' to '[email protected]:5060'
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable NODEST from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __MON_FMT from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __FROMEXTEN from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __TIMESTR from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __YEAR from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __MONTH from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __DAY from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __REC_STATUS from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: channel.c:6496 ast_channel_inherit_variables: Inheriting variable __DIAL_OPTIONS from SIP/334-0000005b to SIP/outbound-vega-0000005c.
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:6421 sip_call: Outgoing Call for 071111111
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:13390 add_sdp: ** Our capability: (ulaw) Video flag: False Text flag: False
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:13391 add_sdp: ** Our prefcodec: (ulaw)
[11:23:05] DEBUG[53219][C-00000040]: chan_sip.c:3387 initialize_initreq: Initializing initreq for method INVITE - callid [email protected]:5060
[11:23:05] DEBUG[27861][C-00000040]: chan_sip.c:4572 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '[email protected]:5060' Request 102: Found
[11:23:05] DEBUG[45212]: manager.c:6169 process_message: Running action 'Command'
[11:23:09] DEBUG[27861]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected] - REGISTER (No RTP)
[11:23:09] DEBUG[27861]: chan_sip.c:16761 parse_register_contact: Store REGISTER's src-IP:port for call routing.
[11:23:09] DEBUG[27861]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected][::1]:5060 - OPTIONS (No RTP)
[11:23:09] DEBUG[27861]: chan_sip.c:8736 change_callid_pvt: SIP call-id changed from '[email protected][::1]:5060' to '[email protected]:5060'
[11:23:09] DEBUG[27861]: chan_sip.c:3387 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[11:23:09] DEBUG[27861]: chan_sip.c:4531 __sip_ack: Stopping retransmission on '[email protected]:5060' of Request 102: Match Found
[11:23:13] DEBUG[27861]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected] - REGISTER (No RTP)
[11:23:13] DEBUG[27861]: chan_sip.c:16761 parse_register_contact: Store REGISTER's src-IP:port for call routing.
[11:23:13] DEBUG[27861]: chan_sip.c:8951 __sip_alloc: Allocating new SIP dialog for [email protected][::1]:5060 - OPTIONS (No RTP)
[11:23:13] DEBUG[27861]: chan_sip.c:8736 change_callid_pvt: SIP call-id changed from '[email protected][::1]:5060' to '[email protected]:5060'
[11:23:13] DEBUG[27861]: chan_sip.c:3387 initialize_initreq: Initializing initreq for method OPTIONS - callid [email protected]:5060
[11:23:13] DEBUG[27861]: chan_sip.c:4531 __sip_ack: Stopping retransmission on '[email protected]:5060' of Request 102: Match Found
[11:23:13] DEBUG[53183]: threadpool.c:1135 worker_idle: Worker thread idle timeout reached. Dying.
[11:23:18] DEBUG[45212]: manager.c:6169 process_message: Running action 'Ping'
[11:23:19] DEBUG[27861][C-00000040]: chan_sip.c:4572 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '[email protected]:5060' Request 102: Found
[11:23:19] DEBUG[27861][C-00000040]: rtp_engine.c:670 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7eff470da020
[11:23:19] DEBUG[27861][C-00000040]: rtp_engine.c:670 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7eff470da020
[11:23:19] DEBUG[27861][C-00000040]: res_rtp_asterisk.c:4881 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7effa6691e48'
[11:23:19] DEBUG[27861][C-00000040]: res_rtp_asterisk.c:4791 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7effa6691e48'
[11:23:19] DEBUG[53219][C-00000040]: rtp_engine.c:1313 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/334-0000005b' with that of 'SIP/outbound-vega-0000005c'
[11:23:19] DEBUG[53219][C-00000040]: chan_sip.c:13390 add_sdp: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True
[11:23:19] DEBUG[53219][C-00000040]: chan_sip.c:13391 add_sdp: ** Our prefcodec: (nothing)
[11:23:19] DEBUG[53219][C-00000040]: chan_sip.c:13586 add_sdp: Setting framing on incoming call: 20
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4443 ast_rtp_read: 0x7effa79fada0 -- Probation learning mode pass with source address 192.168.0.253:10042
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:3524 ast_rtp_write: Ooh, format changed from none to ulaw
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:3369 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0x7eff7cd083d8'
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4443 ast_rtp_read: 0x7eff7cd55970 -- Probation learning mode pass with source address 192.168.0.245:16424
[11:23:19] DEBUG[53219][C-00000040]: chan_sip.c:8556 sip_rtp_read: Oooh, format changed to alaw
[11:23:19] DEBUG[53219][C-00000040]: channel.c:5528 set_format: Channel SIP/334-0000005b setting read format path: alaw -> ulaw
[11:23:19] DEBUG[53219][C-00000040]: channel.c:5528 set_format: Channel SIP/334-0000005b setting write format path: ulaw -> alaw
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:3524 ast_rtp_write: Ooh, format changed from none to ulaw
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:3524 ast_rtp_write: Ooh, format changed from ulaw to alaw
[11:23:19] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4095 ast_rtcp_read: Got RTCP report of 76 bytes
[11:23:19] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:19] DEBUG[53219][C-00000040]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:19] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:19] DEBUG[53205]: manager.c:6169 process_message: Running action 'Command'
[11:23:23] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4095 ast_rtcp_read: Got RTCP report of 76 bytes
[11:23:23] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:23] DEBUG[53219][C-00000040]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:23] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:24] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:24] DEBUG[27861]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:24] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:24] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:24] DEBUG[27861]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:24] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:27] DEBUG[53219][C-00000040]: res_rtp_asterisk.c:4095 ast_rtcp_read: Got RTCP report of 76 bytes
[11:23:27] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:27] DEBUG[53219][C-00000040]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:27] DEBUG[53219][C-00000040]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:28] DEBUG[27861][C-00000040]: chan_sip.c:4515 __sip_ack: Acked pending invite 102
[11:23:28] DEBUG[27861][C-00000040]: chan_sip.c:4531 __sip_ack: Stopping retransmission on '[email protected]:5060' of Request 102: Match
Found
[11:23:28] DEBUG[27861][C-00000040]: rtp_engine.c:670 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7eff470da030
[11:23:28] DEBUG[27861][C-00000040]: rtp_engine.c:670 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 101 based on m type on 0x7eff470da030
[11:23:28] DEBUG[27861][C-00000040]: res_rtp_asterisk.c:4881 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7effa6691e48'
[11:23:28] DEBUG[27861][C-00000040]: res_rtp_asterisk.c:4791 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7effa6691e48'
[11:23:28] DEBUG[53219][C-00000040]: channel.c:5528 set_format: Channel SIP/334-0000005b setting read format path: alaw -> alaw
[11:23:28] DEBUG[53219][C-00000040]: channel.c:5528 set_format: Channel SIP/outbound-vega-0000005c setting write format path: alaw -> ulaw
[11:23:28] DEBUG[53219][C-00000040]: chan_sip.c:7373 sip_answer: SIP answering channel: SIP/334-0000005b
[11:23:28] DEBUG[53219][C-00000040]: chan_sip.c:13390 add_sdp: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True
[11:23:28] DEBUG[53219][C-00000040]: chan_sip.c:13391 add_sdp: ** Our prefcodec: (nothing)
[11:23:28] DEBUG[53219][C-00000040]: chan_sip.c:13586 add_sdp: Setting framing on incoming call: 20
[11:23:28] DEBUG[53219][C-00000040]: dahdi/bridge_native_dahdi.c:714 native_bridge_compatible: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: Cannot use native DAHDI.  Must have two channels.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53219][C-00000040]: bridge_native_rtp.c:332 native_rtp_bridge_compatible: Bridge '2ae608cd-9e6d-49d9-9b4b-c349e5c14018' can not use native RTP bridge
as two channels are required
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:482 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:501 find_best_technology: Chose bridge technology simple_bridge
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:780 bridge_base_init: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: calling simple_bridge technology constructor
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:788 bridge_base_init: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: calling simple_bridge technology start
[11:23:28] DEBUG[53244][C-00000040]: bridge_channel.c:2648 bridge_channel_internal_join: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: 0x7effa66e9978(SIP/outbound-vega-0000005c) is joining
[11:23:28] DEBUG[53244][C-00000040]: bridge_channel.c:2113 bridge_channel_internal_push_full: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: pushing 0x7effa66e9978(SIP/outbound-vega-0000005c)
[11:23:28] DEBUG[53244][C-00000040]: dahdi/bridge_native_dahdi.c:714 native_bridge_compatible: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: Cannot use native DAHDI.  Must have two channels.
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53244][C-00000040]: bridge_native_rtp.c:332 native_rtp_bridge_compatible: Bridge '2ae608cd-9e6d-49d9-9b4b-c349e5c14018' can not use native RTP bridge
as two channels are required
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:482 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:482 find_best_technology: Bridge technology softmix does not have any capabilities we want.
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:501 find_best_technology: Chose bridge technology simple_bridge
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:1032 smart_bridge_operation: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018 is already using the new technology.
[11:23:28] DEBUG[53244][C-00000040]: bridge.c:420 bridge_channel_complete_join: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: 0x7effa66e9978(SIP/outbound-vega-0000005c) is joining simple_bridge technology
[11:23:28] DEBUG[53219][C-00000040]: bridge_channel.c:2648 bridge_channel_internal_join: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: 0x7effa6997e18(SIP/334-0000005b)
is joining
[11:23:28] DEBUG[53219][C-00000040]: bridge_channel.c:2113 bridge_channel_internal_push_full: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: pushing 0x7effa6997e18(SIP/334-0000005b)
[11:23:28] DEBUG[53219][C-00000040]: dahdi/bridge_native_dahdi.c:721 native_bridge_compatible: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: Cannot use native DAHDI.  Channel 'SIP/outbound-vega-0000005c' not compatible.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_dahdi is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53219][C-00000040]: bridge_native_rtp.c:357 native_rtp_bridge_compatible: Bridge '2ae608cd-9e6d-49d9-9b4b-c349e5c14018' can not use native RTP bridge
as channel 'SIP/outbound-vega-0000005c' has DTMF hooks
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:492 find_best_technology: Bridge technology native_rtp is not compatible with properties of existing bridge.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:482 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:482 find_best_technology: Bridge technology softmix does not have any capabilities we want.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:501 find_best_technology: Chose bridge technology simple_bridge
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:1032 smart_bridge_operation: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018 is already using the new technology.
[11:23:28] DEBUG[53219][C-00000040]: bridge.c:420 bridge_channel_complete_join: Bridge 2ae608cd-9e6d-49d9-9b4b-c349e5c14018: 0x7effa6997e18(SIP/334-0000005b) is joining simple_bridge technology
[11:23:28] DEBUG[27838]: cdr.c:1276 cdr_object_finalize: Finalized CDR for SIP/outbound-vega-0000005c - start 1471688585.487746 answer 1471688608.381297 end 1471688608.412244 dispo ANSWERED
[11:23:28] DEBUG[27861][C-00000040]: chan_sip.c:4531 __sip_ack: Stopping retransmission on '[email protected]' of Response 102: Match Found
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[53244][C-00000040]: res_rtp_asterisk.c:4443 ast_rtp_read: 0x7effa79fada0 -- Probation learning mode pass with source address 192.168.0.253:10042
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:28] DEBUG[45212]: manager.c:6169 process_message: Running action 'Setvar'
[11:23:29] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:29] DEBUG[27861]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:29] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:29] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
[11:23:29] DEBUG[27861]: acl.c:795 resolve_first: Multiple addresses. Using the first only
[11:23:29] DEBUG[27861]: acl.c:958 ast_find_ourip: Not an IPv4 nor IPv6 address, cannot get port.
localhost*CLI>