[2008-03-16 08:52:21] DEBUG[27599] chan_zap.c: Requested indication 20 on channel Zap/40-1
[2008-03-16 08:52:21] DEBUG[27599] channel.c: Set channel SIP/172.16.110.22-081b6498 to read format alaw
[2008-03-16 08:52:21] DEBUG[28087] audiohook.c: Read factory 0x81dca50 was pretty quick last time, waiting for them.
[2008-03-16 08:52:21] DEBUG[28087] audiohook.c: Read factory 0x81dca50 was pretty quick last time, waiting for them.
[2008-03-16 08:52:21] DEBUG[27599] rtp.c: Ooh, format changed from unknown to ulaw
[2008-03-16 08:52:21] DEBUG[27599] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[2008-03-16 08:52:22] DEBUG[23248] devicestate.c: Changing state for SIP/172.16.110.22-081b6498 - state 4 (Invalid)
[2008-03-16 08:52:22] DEBUG[23250] app_queue.c: Device 'SIP/172.16.110.22-081b6498' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2008-03-16 08:52:22] DEBUG[23248] devicestate.c: No provider found, checking channel drivers for SIP - 172.16.110.22
[2008-03-16 08:52:22] DEBUG[23248] chan_sip.c: Checking device state for peer 172.16.110.22
[2008-03-16 08:52:22] DEBUG[23248] devicestate.c: Changing state for SIP/172.16.110.22 - state 2 (In use)
[2008-03-16 08:52:22] DEBUG[23250] app_queue.c: Device 'SIP/172.16.110.22' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[2008-03-16 08:52:33] DEBUG[27599] rtp.c: Got RTCP report of 52 bytes
[2008-03-16 08:52:34] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:52:38] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:52:40] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:52:44] DEBUG[27599] rtp.c: Got RTCP report of 52 bytes
[2008-03-16 08:52:54] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:52:55] DEBUG[27599] rtp.c: Got RTCP report of 52 bytes
[2008-03-16 08:53:02] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:53:04] DEBUG[28087] audiohook.c: Write factory 0x81dd46c was pretty quick last time, waiting for them.
[2008-03-16 08:53:05] VERBOSE[23275] logger.c:     -- Channel 0/9, span 2 got hangup request, cause 16
[2008-03-16 08:53:05] DEBUG[27599] channel.c: Didn't get a frame from channel: Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] channel.c: Bridge stops bridging channels Zap/40-1 and SIP/172.16.110.22-081b6498
[2008-03-16 08:53:05] DEBUG[27599] channel.c: Hanging up channel 'SIP/172.16.110.22-081b6498'
[2008-03-16 08:53:05] DEBUG[27599] chan_sip.c: Hangup call SIP/172.16.110.22-081b6498, SIP callid 7b0fe22a0f2bddf530f6bb5d1cfa9f7d@172.16.110.253)
[2008-03-16 08:53:05] DEBUG[27599] devicestate.c: Notification of state change to be queued on device/channel SIP/172.16.110.22-081b6498
[2008-03-16 08:53:05] DEBUG[27599] devicestate.c: Notification of state change to be queued on device/channel SIP/172.16.110.22
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: No provider found, checking channel drivers for SIP - 172.16.110.22-081b6498
[2008-03-16 08:53:05] DEBUG[27599] pbx.c: Extension 666, priority 12 returned normally even though call was hung up
[2008-03-16 08:53:05] DEBUG[27599] channel.c: Soft-Hanging up channel 'Zap/40-1'
[2008-03-16 08:53:05] DEBUG[23248] chan_sip.c: Checking device state for peer 172.16.110.22-081b6498
[2008-03-16 08:53:05] DEBUG[23255] chan_sip.c: = Found Their Call ID: 7b0fe22a0f2bddf530f6bb5d1cfa9f7d@172.16.110.253 Their Tag 68cf8f6d8e194184a379aa41bd5b2718 Our tag: as0868c04d
[2008-03-16 08:53:05] DEBUG[23255] chan_sip.c: Stopping retransmission on '7b0fe22a0f2bddf530f6bb5d1cfa9f7d@172.16.110.253' of Request 103: Match Found
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: Changing state for SIP/172.16.110.22-081b6498 - state 4 (Invalid)
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: No provider found, checking channel drivers for SIP - 172.16.110.22
[2008-03-16 08:53:05] DEBUG[23250] app_queue.c: Device 'SIP/172.16.110.22-081b6498' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2008-03-16 08:53:05] DEBUG[23248] chan_sip.c: Checking device state for peer 172.16.110.22
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: Changing state for SIP/172.16.110.22 - state 1 (Not in use)
[2008-03-16 08:53:05] DEBUG[23250] app_queue.c: Device 'SIP/172.16.110.22' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2008-03-16 08:53:05] DEBUG[27599] channel.c: Hanging up channel 'Zap/40-1'
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: zt_hangup(Zap/40-1)
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Hangup: channel: 40 index = 0, normal = 56, callwait = -1, thirdcall = -1
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
[2008-03-16 08:53:05] VERBOSE[28087] logger.c:   == End recording Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: disabled echo cancellation on channel 40
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Updated conferencing on 40, with 0 conference users
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] chan_zap.c: disabled echo cancellation on channel 40
[2008-03-16 08:53:05] VERBOSE[27599] logger.c:     -- Hungup 'Zap/40-1'
[2008-03-16 08:53:05] DEBUG[27599] devicestate.c: Notification of state change to be queued on device/channel Zap/40-1
[2008-03-16 08:53:05] DEBUG[27599] devicestate.c: Notification of state change to be queued on device/channel Zap/40
[2008-03-16 08:53:05] VERBOSE[23255] logger.c: Really destroying SIP dialog '7b0fe22a0f2bddf530f6bb5d1cfa9f7d@172.16.110.253' Method: INVITE
[2008-03-16 08:53:05] DEBUG[23255] sched.c: Attempted to delete nonexistent schedule entry 8!
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: No provider found, checking channel drivers for Zap - 40-1
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: Changing state for Zap/40-1 - state 0 (Unknown)
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: No provider found, checking channel drivers for Zap - 40
[2008-03-16 08:53:05] DEBUG[23250] app_queue.c: Device 'Zap/40-1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[2008-03-16 08:53:05] DEBUG[23248] devicestate.c: Changing state for Zap/40 - state 0 (Unknown)
[2008-03-16 08:53:05] DEBUG[23250] app_queue.c: Device 'Zap/40' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
[2008-03-16 08:53:19] DEBUG[23267] chan_iax2.c: Raw Hangup 172.16.0.75:4661, src=0, dst=0