rendered paste bodyMay 31 08:09:16] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 08:09:16] DEBUG[2270] chan_sip.c: Allocating new SIP dialog for 1609492007-839465162383105671@208.51.102.30 - INVITE (With RTP)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[May 31 08:09:16] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 08:09:16] DEBUG[2270] chan_sip.c: T38 state changed to 0 on channel <none>
[May 31 08:09:16] DEBUG[2270] chan_sip.c: We're settling with these formats: 0x4 (ulaw)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: Checking SIP call limits for device
[May 31 08:09:16] DEBUG[2270] chan_sip.c: Updating call counter for incoming call
[May 31 08:09:16] DEBUG[2270] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: *** Joint capabilities are 0x4 (ulaw)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: *** Our capabilities are 0x8000d (g723|ulaw|alaw|h263)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[May 31 08:09:16] DEBUG[2270] chan_sip.c: This channel will not be able to handle video.
[May 31 08:09:16] DEBUG[2270] chan_sip.c: build_route: Contact hop: <sip:208.51.102.30:5080>
[May 31 08:09:16] DEBUG[2270] chan_sip.c: SIP/5080-09587fa8: New call is still down.... Trying...
[May 31 08:09:16] DEBUG[2270] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:16] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:16] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:16] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "EXTEN is 18666777934")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "CHANNEL is SIP/5080-09587fa8")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "CONTEXT is inbound")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "CALLERIDNUM is ")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "CALLERID is ")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing NoOp("SIP/5080-09587fa8", "Sending to voicemailbox '18666777934'")
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing Answer("SIP/5080-09587fa8", "")
[May 31 08:09:16] DEBUG[10157] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:16] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:16] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:16] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:16] DEBUG[10157] chan_sip.c: SIP answering channel: SIP/5080-09587fa8
[May 31 08:09:16] DEBUG[10157] chan_sip.c: Setting framing from config on incoming call
[May 31 08:09:16] DEBUG[10157] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True
[May 31 08:09:16] DEBUG[10157] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[May 31 08:09:16] DEBUG[10157] chan_sip.c: -- Done with adding codecs to SDP
[May 31 08:09:16] DEBUG[10157] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[May 31 08:09:16] DEBUG[10157] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw)
[May 31 08:09:16] VERBOSE[10157] logger.c: [May 31 08:09:16] -- Executing wait("SIP/5080-09587fa8", "1")
[May 31 08:09:16] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1609492007-839465162383105671@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as7e7bbc4a
[May 31 08:09:16] DEBUG[2270] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 31 08:09:16] DEBUG[2270] chan_sip.c: Stopping retransmission on '1609492007-839465162383105671@208.51.102.30' of Response 1: Match Not Found
[May 31 08:09:17] VERBOSE[10157] logger.c: [May 31 08:09:17] -- Executing Playback("SIP/5080-09587fa8", "you-have-reached-a-test-number")
[May 31 08:09:17] DEBUG[10157] rtp.c: Ooh, format changed from unknown to ulaw
[May 31 08:09:17] DEBUG[10157] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[May 31 08:09:17] VERBOSE[10157] logger.c: [May 31 08:09:17] -- <SIP/5080-09587fa8> Playing 'you-have-reached-a-test-number' (language 'en')
[May 31 08:09:18] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1609492007-839465162383105671@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as7e7bbc4a
[May 31 08:09:18] DEBUG[2270] chan_sip.c: **** Received BYE (8) - Command in SIP BYE
[May 31 08:09:18] DEBUG[2270] chan_sip.c: Setting SIP_ALREADYGONE on dialog 1609492007-839465162383105671@208.51.102.30
[May 31 08:09:18] DEBUG[2270] chan_sip.c: Received bye, issuing owner hangup
[May 31 08:09:18] DEBUG[10157] pbx.c: Spawn extension (inbound,18666777934,9) exited non-zero on 'SIP/5080-09587fa8'
[May 31 08:09:18] VERBOSE[10157] logger.c: [May 31 08:09:18] == Spawn extension (inbound, 18666777934, 9) exited non-zero on 'SIP/5080-09587fa8'
[May 31 08:09:18] VERBOSE[10157] logger.c: [May 31 08:09:18] > cdr_odbc: Query Successful!
[May 31 08:09:18] DEBUG[10157] channel.c: Hanging up channel 'SIP/5080-09587fa8'
[May 31 08:09:18] DEBUG[10157] chan_sip.c: Hangup call SIP/5080-09587fa8, SIP callid 1609492007-839465162383105671@208.51.102.30)
[May 31 08:09:18] DEBUG[10157] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:18] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:18] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:18] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:19] VERBOSE[2270] logger.c: [May 31 08:09:19] Really destroying SIP dialog '1609492007-839465162383105671@208.51.102.30' Method: BYE
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Allocating new SIP dialog for 1610142007-839465162393105992@208.51.102.30 - INVITE (With RTP)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Setting NAT on RTP to Off
[May 31 08:09:41] DEBUG[2270] chan_sip.c: T38 state changed to 0 on channel <none>
[May 31 08:09:41] DEBUG[2270] chan_sip.c: We're settling with these formats: 0x4 (ulaw)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Checking SIP call limits for device
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Updating call counter for incoming call
[May 31 08:09:41] DEBUG[2270] chan_sip.c: *** Our native formats are 0x4 (ulaw)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: *** Joint capabilities are 0x4 (ulaw)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: *** Our capabilities are 0x8000d (g723|ulaw|alaw|h263)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw)
[May 31 08:09:41] DEBUG[2270] chan_sip.c: This channel will not be able to handle video.
[May 31 08:09:41] DEBUG[2270] chan_sip.c: build_route: Contact hop: <sip:208.51.102.30:5080>
[May 31 08:09:41] DEBUG[2270] chan_sip.c: SIP/5080-09587fa8: New call is still down.... Trying...
[May 31 08:09:41] DEBUG[2270] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:41] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:41] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:41] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "EXTEN is 18666777934")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "CHANNEL is SIP/5080-09587fa8")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "CONTEXT is inbound")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "CALLERIDNUM is ")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "CALLERID is ")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing NoOp("SIP/5080-09587fa8", "Sending to voicemailbox '18666777934'")
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing Answer("SIP/5080-09587fa8", "")
[May 31 08:09:41] DEBUG[10158] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:41] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:41] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:41] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:41] DEBUG[10158] chan_sip.c: SIP answering channel: SIP/5080-09587fa8
[May 31 08:09:41] DEBUG[10158] chan_sip.c: Setting framing from config on incoming call
[May 31 08:09:41] DEBUG[10158] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True
[May 31 08:09:41] DEBUG[10158] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[May 31 08:09:41] DEBUG[10158] chan_sip.c: -- Done with adding codecs to SDP
[May 31 08:09:41] DEBUG[10158] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[May 31 08:09:41] DEBUG[10158] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw)
[May 31 08:09:41] VERBOSE[10158] logger.c: [May 31 08:09:41] -- Executing wait("SIP/5080-09587fa8", "1")
[May 31 08:09:41] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1610142007-839465162393105992@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as0ed073a6
[May 31 08:09:41] DEBUG[2270] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 31 08:09:41] DEBUG[2270] chan_sip.c: Stopping retransmission on '1610142007-839465162393105992@208.51.102.30' of Response 1: Match Not Found
[May 31 08:09:42] VERBOSE[10158] logger.c: [May 31 08:09:42] -- Executing Voicemail("SIP/5080-09587fa8", "")
[May 31 08:09:42] DEBUG[10158] rtp.c: Ooh, format changed from unknown to ulaw
[May 31 08:09:42] DEBUG[10158] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[May 31 08:09:42] VERBOSE[10158] logger.c: [May 31 08:09:42] -- <SIP/5080-09587fa8> Playing 'vm-whichbox' (language 'en')
[May 31 08:09:47] DEBUG[2270] chan_sip.c: = Found Their Call ID: 1610142007-839465162393105992@208.51.102.30 Their Tag GR52RWG346-34 Our tag: as0ed073a6
[May 31 08:09:47] DEBUG[2270] chan_sip.c: **** Received BYE (8) - Command in SIP BYE
[May 31 08:09:47] DEBUG[2270] chan_sip.c: Setting SIP_ALREADYGONE on dialog 1610142007-839465162393105992@208.51.102.30
[May 31 08:09:47] DEBUG[2270] chan_sip.c: Received bye, issuing owner hangup
[May 31 08:09:47] DEBUG[10158] pbx.c: Spawn extension (inbound,18666777934,9) exited non-zero on 'SIP/5080-09587fa8'
[May 31 08:09:47] VERBOSE[10158] logger.c: [May 31 08:09:47] == Spawn extension (inbound, 18666777934, 9) exited non-zero on 'SIP/5080-09587fa8'
[May 31 08:09:47] VERBOSE[10158] logger.c: [May 31 08:09:47] > cdr_odbc: Query Successful!
[May 31 08:09:47] DEBUG[10158] channel.c: Hanging up channel 'SIP/5080-09587fa8'
[May 31 08:09:47] DEBUG[10158] chan_sip.c: Hangup call SIP/5080-09587fa8, SIP callid 1610142007-839465162393105992@208.51.102.30)
[May 31 08:09:47] DEBUG[10158] devicestate.c: Notification of state change to be queued on device/channel SIP/5080-09587fa8
[May 31 08:09:47] DEBUG[2267] devicestate.c: No provider found, checking channel drivers for SIP - 5080
[May 31 08:09:47] DEBUG[2267] chan_sip.c: Checking device state for peer 5080
[May 31 08:09:47] DEBUG[2267] devicestate.c: Changing state for SIP/5080 - state 4 (Invalid)
[May 31 08:09:48] VERBOSE[2270] logger.c: [May 31 08:09:48] Really destroying SIP dialog '1610142007-839465162393105992@208.51.102.30' Method: BYE