[2010-01-19 10:25:40] VERBOSE[4762] logger.c: Asterisk Event Logger restarted
[2010-01-19 10:25:40] VERBOSE[4762] logger.c: Asterisk Queue Logger restarted
[2010-01-19 10:25:55] NOTICE[22407] chan_iax2.c: ip callno count decremented to 0 for 208.72.186.66
[2010-01-19 10:25:55] NOTICE[22401] chan_iax2.c: ip callno count incremented to 1 for 208.72.186.66
[2010-01-19 10:25:55] NOTICE[22402] chan_iax2.c: schedule decrement of callno used for 208.72.186.66 in 60 seconds
[2010-01-19 10:25:55] DEBUG[22402] chan_iax2.c: Peer VoIPjetBACKUP: got pong, lastms 110, historicms 110, maxms 2000
[2010-01-19 10:26:02] VERBOSE[2314] logger.c: Received Softkey Event: New Call(0/0)
[2010-01-19 10:26:02] VERBOSE[2314] logger.c: skinny_new: tmp->nativeformats=268 fmt=4
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 0088 (16 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 0111 (36 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 0116 (16 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] logger.c: Attempting to Clear display on Skinny 0001@SEP0006283E0E91
[2010-01-19 10:26:02] VERBOSE[2314] logger.c: Clearing Display
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 009A (12 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 0082 (28 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] chan_skinny.c: writing packet type 0110 (28 bytes) to socket 30
[2010-01-19 10:26:02] VERBOSE[2314] logger.c: RECEIVED UNKNOWN MESSAGE TYPE:  49
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [0]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [8]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [9]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [9]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [9]
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [8]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [9]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [5]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[2314] logger.c: Collected digit: [2]
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:03] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:03] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[2314] logger.c: Collected digit: [0]
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[2314] logger.c: Collected digit: [8]
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[2314] logger.c: Collected digit: [6]
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:04] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:04] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:07] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:07] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel Skinny/0001@SEP0006283E0E91
[2010-01-19 10:26:07] VERBOSE[4764] chan_skinny.c: writing packet type 0105 (100 bytes) to socket 30
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] VERBOSE[4764] logger.c:   Step 0 : Input pattern 089*********
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] VERBOSE[4764] logger.c:   Step 1 : Pattern 0Z. - DE National (long distance) call| remove the leading zero & add the international prefix to promote to e.164
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Expression result is '"+4989*********"'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'NoOp'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] VERBOSE[4764] logger.c:   Step 2 : Service path selected is DAHDI
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Expression result is '"DAHDI"'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'NoOp'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Function result is '"******** ********" <49809********>'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] VERBOSE[4764] logger.c:   Step 3 : Pattern +49. - this is a DE national call| drop the leading 3 chars and prepend 0
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Expression result is '"089*********"'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'NoOp'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'NoOp'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Function result is '"******** ********" <49809********>'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:07] VERBOSE[4764] logger.c:   Starting number : 089********* Dial string : 089********* Service Path DAHDI/G0 Caller ID "******** ********" <49809********>
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for Skinny - 0001@SEP0006283E0E91
[2010-01-19 10:26:07] DEBUG[22394] devicestate.c: Changing state for Skinny/0001@SEP0006283E0E91 - state 2 (In use)
[2010-01-19 10:26:07] VERBOSE[2314] logger.c: Received Open Receive Channel Ack
[2010-01-19 10:26:07] VERBOSE[2314] logger.c: ipaddr = 192.168.0.156:32496
[2010-01-19 10:26:07] VERBOSE[2314] logger.c: ourip = 192.168.0.200:27234
[2010-01-19 10:26:07] VERBOSE[2314] logger.c: Setting payloadType to '4' (20 ms)
[2010-01-19 10:26:07] VERBOSE[2314] chan_skinny.c: writing packet type 008A (116 bytes) to socket 30
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'System'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Monitor'
[2010-01-19 10:26:07] DEBUG[4764] pbx.c: Launching 'Dial'
[2010-01-19 10:26:07] DEBUG[4764] chan_dahdi.c: Using channel 4
[2010-01-19 10:26:07] DEBUG[4764] rtp.c: Channel 'DAHDI/4-1' has no RTP, not doing anything
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable DIALEDTIME.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable ANSWEREDTIME.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable DIALEDPEERNAME.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable DIALEDPEERNUMBER.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable DIALSTATUS.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Copying hard-transferable variable MONITORED.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable SYSTEMSTATUS.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable dialString.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable svcPath.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable e164exten.
[2010-01-19 10:26:07] DEBUG[4764] channel.c: Not copying variable ~~EXTEN~~.
[2010-01-19 10:26:07] DEBUG[4764] chan_dahdi.c: Dialing '089*********'
[2010-01-19 10:26:07] DEBUG[4764] chan_dahdi.c: Deferring dialing...
[2010-01-19 10:26:07] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel DAHDI/4
[2010-01-19 10:26:07] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for DAHDI - 4
[2010-01-19 10:26:07] DEBUG[22394] devicestate.c: Changing state for DAHDI/4 - state 2 (In use)
[2010-01-19 10:26:08] DEBUG[4764] chan_dahdi.c: Exception on 20, channel 4
[2010-01-19 10:26:08] DEBUG[4764] chan_dahdi.c: Got event Hook Transition Complete(12) on channel 4 (index 0)
[2010-01-19 10:26:08] DEBUG[4764] chan_dahdi.c: Sent deferred digit string: T089*********w
[2010-01-19 10:26:10] DEBUG[4764] chan_dahdi.c: Exception on 20, channel 4
[2010-01-19 10:26:10] DEBUG[4764] chan_dahdi.c: Got event Dial Complete(9) on channel 4 (index 0)
[2010-01-19 10:26:10] DEBUG[4764] chan_dahdi.c: Enabled echo cancellation on channel 4
***	[2010-01-19 10:26:10] DEBUG[4764] chan_dahdi.c: Done dialing, but waiting for progress detection before doing more...
[2010-01-19 10:26:10] DEBUG[4764] rtp.c: Ooh, format changed from unknown to ulaw
[2010-01-19 10:26:10] DEBUG[4764] rtp.c: Created smoother: format: 4 ms: 20 len: 160
[2010-01-19 10:26:10] DEBUG[4764] chan_skinny.c: Oooh, format changed to 4
[2010-01-19 10:26:13] NOTICE[22407] chan_iax2.c: ip callno count decremented to 1 for 66.246.72.34
[2010-01-19 10:26:13] NOTICE[22404] chan_iax2.c: ip callno count incremented to 2 for 66.246.72.34
[2010-01-19 10:26:13] NOTICE[22405] chan_iax2.c: schedule decrement of callno used for 66.246.72.34 in 60 seconds
[2010-01-19 10:26:13] DEBUG[22405] chan_iax2.c: Peer VoIPjetPRIMARY2: got pong, lastms 118, historicms 118, maxms 2000
[2010-01-19 10:26:16] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel DAHDI/4
[2010-01-19 10:26:16] DEBUG[4764] rtp.c: Channel 'DAHDI/4-1' has no RTP, not doing anything
***	[2010-01-19 10:26:16] VERBOSE[4764] logger.c: skinny_answer(Skinny/0001@SEP0006283E0E91-48) on 0001@SEP0006283E0E91-48
[2010-01-19 10:26:16] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel Skinny/0001@SEP0006283E0E91
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] logger.c: Setting Callinfo to ******** ********(49809********) from _.(_.) on SEP0006283E0E91(1)
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 008F (396 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 0111 (36 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 0110 (28 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 011D (44 bytes) to socket 30
***	[2010-01-19 10:26:16] VERBOSE[4764] logger.c: Displaying Prompt Status 'Connected'
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 0112 (56 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] logger.c:     -- Asked to indicate 'Stop tone' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:16] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:16] VERBOSE[4764] logger.c:     -- Asked to indicate 'UNKNOWN-20' condition on channel Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:16] DEBUG[4764] chan_dahdi.c: Requested indication 20 on channel DAHDI/4-1
[2010-01-19 10:26:16] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for DAHDI - 4
[2010-01-19 10:26:16] DEBUG[22394] devicestate.c: Changing state for DAHDI/4 - state 2 (In use)
[2010-01-19 10:26:16] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for Skinny - 0001@SEP0006283E0E91
[2010-01-19 10:26:16] DEBUG[22394] devicestate.c: Changing state for Skinny/0001@SEP0006283E0E91 - state 2 (In use)
[2010-01-19 10:26:18] DEBUG[4764] chan_dahdi.c: DTMF digit: A on DAHDI/4-1
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Set channel Skinny/0001@SEP0006283E0E91-48 to write format slin
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Scheduling timer at 160 sample intervals
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=28)
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Set channel Skinny/0001@SEP0006283E0E91-48 to write format ulaw
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Scheduling timer at 0 sample intervals
[2010-01-19 10:26:18] DEBUG[4764] channel.c: Thread 1117931856 Blocking 'Skinny/0001@SEP0006283E0E91-48', already blocked by thread 1117931856 in procedure ast_write
[2010-01-19 10:26:20] NOTICE[22407] chan_iax2.c: ip callno count decremented to 1 for 66.246.72.34
[2010-01-19 10:26:20] NOTICE[22397] chan_iax2.c: ip callno count incremented to 2 for 66.246.72.34
[2010-01-19 10:26:20] NOTICE[22398] chan_iax2.c: schedule decrement of callno used for 66.246.72.34 in 60 seconds
[2010-01-19 10:26:20] DEBUG[22398] chan_iax2.c: Peer VoIPjetPRIMARY1: got pong, lastms 125, historicms 125, maxms 2000
[2010-01-19 10:26:26] DEBUG[22410] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2010-01-19 10:26:26] DEBUG[22410] acl.c: ##### Testing 192.168.0.199 with 192.168.0.0
[2010-01-19 10:26:26] DEBUG[22410] chan_sip.c: = Found Their Call ID: 3e73b06978c5de7c11a3daa46f249e74@brkhlo.dyndns.org Their Tag  Our tag: as4af03617
[2010-01-19 10:26:26] DEBUG[22410] chan_sip.c: Stopping retransmission on '3e73b06978c5de7c11a3daa46f249e74@brkhlo.dyndns.org' of Request 102: Match Found
[2010-01-19 10:26:26] VERBOSE[22410] logger.c: Really destroying SIP dialog '3e73b06978c5de7c11a3daa46f249e74@brkhlo.dyndns.org' Method: OPTIONS
[2010-01-19 10:26:36] DEBUG[22410] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[2010-01-19 10:26:36] DEBUG[22410] acl.c: ##### Testing 192.168.0.197 with 192.168.0.0
[2010-01-19 10:26:37] DEBUG[22410] chan_sip.c: = Found Their Call ID: 0da33605575d8b283d31840a0ee4ac44@brkhlo.dyndns.org Their Tag  Our tag: as5c2e07e3
[2010-01-19 10:26:37] DEBUG[22410] chan_sip.c: Stopping retransmission on '0da33605575d8b283d31840a0ee4ac44@brkhlo.dyndns.org' of Request 102: Match Found
[2010-01-19 10:26:37] VERBOSE[22410] logger.c: Really destroying SIP dialog '0da33605575d8b283d31840a0ee4ac44@brkhlo.dyndns.org' Method: OPTIONS
[2010-01-19 10:26:45] VERBOSE[2314] logger.c: Received Softkey Event: End Call(1/48)
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0106 (28 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 008B (32 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0088 (16 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] logger.c: Clearing Prompt
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0113 (20 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0111 (36 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0110 (28 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0116 (16 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[2314] logger.c: Skinny 0001@SEP0006283E0E91 went on hook
[2010-01-19 10:26:45] VERBOSE[2314] chan_skinny.c: writing packet type 0094 (48 bytes) to socket 30
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Didn't get a frame from channel: Skinny/0001@SEP0006283E0E91-48
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: Requested indication 20 on channel DAHDI/4-1
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Bridge stops bridging channels Skinny/0001@SEP0006283E0E91-48 and DAHDI/4-1
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '"******** ********" <+4980922559018>'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '+4980922559018'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '_.'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'inHouseLines'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'Skinny/0001@SEP0006283E0E91-48'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'DAHDI/4-1'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'Dial'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'DAHDI/G0/089*********|14400|g'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '2010-01-19 10:26:02'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '2010-01-19 10:26:16'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '2010-01-19 10:26:45'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '43'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '29'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'ANSWERED'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is 'DOCUMENTATION'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '(null)'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '1263893162.631'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Function result is '(null)'
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Hanging up channel 'DAHDI/4-1'
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: dahdi_hangup(DAHDI/4-1)
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: Hangup: channel: 4 index = 0, normal = 20, callwait = -1, thirdcall = -1
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: disabled echo cancellation on channel 4
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/4-1
[2010-01-19 10:26:45] DEBUG[4764] chan_dahdi.c: Updated conferencing on 4, with 0 conference users
[2010-01-19 10:26:45] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel DAHDI/4
[2010-01-19 10:26:45] DEBUG[4764] rtp.c: Channel '<unspecified>' has no RTP, not doing anything
[2010-01-19 10:26:45] DEBUG[4764] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Spawn extension (inHouseLines,_.,17) exited non-zero on 'Skinny/0001@SEP0006283E0E91-48'
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Soft-Hanging up channel 'Skinny/0001@SEP0006283E0E91-48'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Set'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:45] VERBOSE[4764] logger.c:   Step 0 : Input pattern h
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Goto'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Verbose'
[2010-01-19 10:26:45] VERBOSE[4764] logger.c:  Step 1 : BUGCHECK.. DEFAULT triggered| invalid dial pattern attempted 089********* Call ID 1263893162.631
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Playback'
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Set channel Skinny/0001@SEP0006283E0E91-48 to write format gsm
[2010-01-19 10:26:45] WARNING[4764] file.c: Failed to write frame
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Scheduling timer at 0 sample intervals
[2010-01-19 10:26:45] WARNING[4764] app_playback.c: ast_streamfile failed on Skinny/0001@SEP0006283E0E91-48 for invalid
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Launching 'Hangup'
[2010-01-19 10:26:45] DEBUG[4764] pbx.c: Spawn extension (inHouseLines,sw-1-h,12) exited non-zero on 'Skinny/0001@SEP0006283E0E91-48'
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Scheduling timer at 0 sample intervals
[2010-01-19 10:26:45] DEBUG[4764] channel.c: Hanging up channel 'Skinny/0001@SEP0006283E0E91-48'
[2010-01-19 10:26:45] VERBOSE[4764] logger.c: skinny_hangup(Skinny/0001@SEP0006283E0E91-48) on 0001@SEP0006283E0E91
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0083 (20 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0106 (28 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 008B (32 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0088 (16 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] logger.c: Clearing Prompt
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0113 (20 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0111 (36 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0110 (28 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0116 (16 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] logger.c: Setting ringer mode to '1'.
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0085 (32 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0086 (24 bytes) to socket 30
[2010-01-19 10:26:45] VERBOSE[4764] chan_skinny.c: writing packet type 0094 (48 bytes) to socket 30
[2010-01-19 10:26:45] DEBUG[4764] res_monitor.c: monitor executing /usr/local/etc/asterisk/record "/var/spool/asterisk/monitor/1263893162.631-in.WAV" "/var/spool/asterisk/monitor/1263893162.631-out.WAV" "/var/spool/asterisk/monitor/1263893162.631.WAV"  &
[2010-01-19 10:26:45] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for DAHDI - 4
[2010-01-19 10:26:45] DEBUG[4764] devicestate.c: Notification of state change to be queued on device/channel Skinny/0001@SEP0006283E0E91
[2010-01-19 10:26:45] DEBUG[22394] devicestate.c: Changing state for DAHDI/4 - state 0 (Unknown)
[2010-01-19 10:26:45] DEBUG[22394] devicestate.c: No provider found, checking channel drivers for Skinny - 0001@SEP0006283E0E91
[2010-01-19 10:26:45] DEBUG[22394] devicestate.c: Changing state for Skinny/0001@SEP0006283E0E91 - state 0 (Unknown)
[2010-01-19 10:26:45] VERBOSE[2314] logger.c: RECEIVED UNKNOWN MESSAGE TYPE:  49
[2010-01-19 10:26:49] VERBOSE[2314] chan_skinny.c: writing packet type 0100 (12 bytes) to socket 30
[2010-01-19 10:26:49] VERBOSE[2314] chan_skinny.c: writing packet type 0094 (48 bytes) to socket 30
[2010-01-19 10:28:22] VERBOSE[4806] logger.c:   Step 0 : Input pattern 080843877
[2010-01-19 10:28:22] VERBOSE[4806] logger.c:   Step 1 : Pattern 0Z. - DE National (long distance) call| remove the leading zero & add the international prefix to promote to e.164
[2010-01-19 10:28:22] VERBOSE[4806] logger.c:   Step 2 : Service path selected is VoIPjet
[2010-01-19 10:28:22] VERBOSE[4806] logger.c:   Step 3 : Pattern DEFAULT| treat it as an international call 
[2010-01-19 10:28:22] VERBOSE[4806] logger.c:   Starting number : 080843877 Dial string : 0114980843877 Service Path IAX2/4785@VoIPjetPRIMARY1 Caller ID "******** ********" <49809********>
[2010-01-19 10:28:22] DEBUG[4806] chan_iax2.c: prepending 8 to prefs
[2010-01-19 10:28:33] VERBOSE[4806] logger.c:   Step 0 : Input pattern h
[2010-01-19 10:28:33] VERBOSE[4806] logger.c:  Step 1 : BUGCHECK.. DEFAULT triggered| invalid dial pattern attempted 0114980843877 Call ID 1263893302.633
[2010-01-19 10:28:33] DEBUG[4806] res_monitor.c: monitor executing /usr/local/etc/asterisk/record "/var/spool/asterisk/monitor/1263893302.633-in.WAV" "/var/spool/asterisk/monitor/1263893302.633-out.WAV" "/var/spool/asterisk/monitor/1263893302.633.WAV"  &
[2010-01-19 10:28:43] VERBOSE[4843] logger.c:   Step 0 : Input pattern 01707944701
[2010-01-19 10:28:43] VERBOSE[4843] logger.c:   Step 1 : Pattern 0Z. - DE National (long distance) call| remove the leading zero & add the international prefix to promote to e.164
[2010-01-19 10:28:43] VERBOSE[4843] logger.c:   Step 2 : Service path selected is VoIPjet
[2010-01-19 10:28:43] VERBOSE[4843] logger.c:   Step 3 : Pattern DEFAULT| treat it as an international call 
[2010-01-19 10:28:43] VERBOSE[4843] logger.c:   Starting number : 01707944701 Dial string : 011491707944701 Service Path IAX2/4785@VoIPjetPRIMARY1 Caller ID "******** ********" <49809********>
[2010-01-19 10:28:43] DEBUG[4843] chan_iax2.c: prepending 8 to prefs
[2010-01-19 10:28:49] VERBOSE[2314] chan_skinny.c: writing packet type 0100 (12 bytes) to socket 30
[2010-01-19 10:28:49] VERBOSE[2314] chan_skinny.c: writing packet type 0094 (48 bytes) to socket 30
[2010-01-19 10:28:51] VERBOSE[4843] logger.c:   Step 0 : Input pattern h
[2010-01-19 10:28:51] VERBOSE[4843] logger.c:  Step 1 : BUGCHECK.. DEFAULT triggered| invalid dial pattern attempted 011491707944701 Call ID 1263893323.636
[2010-01-19 10:28:51] DEBUG[4843] res_monitor.c: monitor executing /usr/local/etc/asterisk/record "/var/spool/asterisk/monitor/1263893323.636-in.WAV" "/var/spool/asterisk/monitor/1263893323.636-out.WAV" "/var/spool/asterisk/monitor/1263893323.636.WAV"  &