[Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on RTP to Off [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on VRTP to Off [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Allocating new SIP dialog for 70318aa8-d913f081-37ad8cee@192.168.21.68 - INVITE (With RTP) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on RTP to Off [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on VRTP to Off [Sep 15 16:03:41] DEBUG[15190] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=28) [Sep 15 16:03:41] DEBUG[15879] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=57) [Sep 15 16:03:41] DEBUG[14118] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=98) [Sep 15 16:03:41] DEBUG[15665] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=109) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: = Found Their Call ID: 70318aa8-d913f081-37ad8cee@192.168.21.68 Their Tag 5B6D07FF-9741D504 Our tag: as5bf57fed [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Stopping retransmission on '70318aa8-d913f081-37ad8cee@192.168.21.68' of Response 1: Match Found [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: = Found Their Call ID: 70318aa8-d913f081-37ad8cee@192.168.21.68 Their Tag 5B6D07FF-9741D504 Our tag: as5bf57fed [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on RTP to Off [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Setting NAT on VRTP to Off [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: T38 state changed to 0 on channel [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Checking SIP call limits for device 1893 [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Updating call counter for incoming call [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: Call from peer '1893' is 1 out of 4 [Sep 15 16:03:41] DEBUG[16316] devicestate.c: Notification of state change to be queued on device/channel SIP/1893 [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: *** Our native formats are 0x8 (alaw) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: *** Our capabilities are 0xa (gsm|alaw) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: This channel will not be able to handle video. [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: build_route: Contact hop: [Sep 15 16:03:41] DEBUG[16316] chan_sip.c: SIP/1893-b6c3f660: New call is still down.... Trying... [Sep 15 16:03:41] DEBUG[16316] devicestate.c: Notification of state change to be queued on device/channel SIP/1893 [Sep 15 16:03:41] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1893 [Sep 15 16:03:41] DEBUG[16312] chan_sip.c: Checking device state for peer 1893 [Sep 15 16:03:41] DEBUG[16312] devicestate.c: Changing state for SIP/1893 - state 2 (In use) [Sep 15 16:03:41] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1893 [Sep 15 16:03:41] DEBUG[16312] chan_sip.c: Checking device state for peer 1893 [Sep 15 16:03:41] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1893 [Sep 15 16:03:41] DEBUG[16312] chan_sip.c: Checking device state for peer 1893 [Sep 15 16:03:41] DEBUG[16312] devicestate.c: Changing state for SIP/1893 - state 2 (In use) [Sep 15 16:03:41] DEBUG[16312] devicestate.c: No provider found, checking channel drivers for SIP - 1893 [Sep 15 16:03:41] DEBUG[16312] chan_sip.c: Checking device state for peer 1893 [Sep 15 16:03:41] DEBUG[16317] app_queue.c: Device 'SIP/1893' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 15 16:03:41] DEBUG[16317] app_queue.c: Device 'SIP/1893' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 15 16:03:41] DEBUG[16723] pbx.c: Launching 'Macro' [Sep 15 16:03:41] DEBUG[16723] pbx.c: Launching 'Set' [Sep 15 16:03:41] DEBUG[16723] app_macro.c: Executed application: Set [Sep 15 16:03:41] DEBUG[16723] pbx.c: Function result is '1893' [Sep 15 16:03:41] DEBUG[16723] pbx.c: Launching 'Set'