Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Attempting call on LOCAL/s@voipstation for *0*XXXXXXXXX@pbx:1 (Retry 1)
Jun 14 10:28:48 DEBUG[9447] devicestate.c: Changing state for Local/s@voipstation - state 2 (In use)
Jun 14 10:28:48 DEBUG[2886] pbx.c: Launching 'Answer'
Jun 14 10:28:48 VERBOSE[2886] logger.c: -- Executing Answer("Local/s@voipstation-ceb4,2", "") in new stack
Jun 14 10:28:48 DEBUG[2886] pbx.c: Launching 'Read'
Jun 14 10:28:48 VERBOSE[2886] logger.c: -- Executing Read("Local/s@voipstation-ceb4,2", "money|||||100") in new stack
Jun 14 10:28:48 DEBUG[2887] app_queue.c: Device 'Local/s@voipstation' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'Set'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing Set("Local/s@voipstation-ceb4,1", "ToBeDialed=XXXXXXXXX") in new stack
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'Goto'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing Goto("Local/s@voipstation-ceb4,1", "plain-capi-out|s|1") in new stack
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Goto (plain-capi-out,s,1)
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'Set'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing Set("Local/s@voipstation-ceb4,1", "OrigCallNum=") in new stack
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'SetCallerPres'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing SetCallerPres("Local/s@voipstation-ceb4,1", "") in new stack
Jun 14 10:28:48 WARNING[2885] app_setcallerid.c: '' is not a valid presentation (see 'show application SetCallerPres')
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'NoOp'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing NoOp("Local/s@voipstation-ceb4,1", "") in new stack
Jun 14 10:28:48 DEBUG[2885] pbx.c: Launching 'Dial'
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Executing Dial("Local/s@voipstation-ceb4,1", "CAPI/ISDN1/:XXXXXXXXX||H") in new stack
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-plain-capi-out-s-4.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-plain-capi-out-s-3.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-plain-capi-out-s-2.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable OrigCallNum.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-plain-capi-out-s-1.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-pbx-*0*XXXXXXXXX-2.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable ToBeDialed.
Jun 14 10:28:48 DEBUG[2885] channel.c: Not copying variable STACK-pbx-*0*XXXXXXXXX-1.
Jun 14 10:28:48 VERBOSE[2885] logger.c: -- Called ISDN1/:XXXXXXXXX
Jun 14 10:28:48 DEBUG[2885] channel.c: Set channel CAPI/ISDN1/XXXXXXXXX-2a to read format slin
Jun 14 10:28:48 DEBUG[2885] channel.c: Set channel CAPI/ISDN1/XXXXXXXXX-2a to write format slin
Jun 14 10:28:48 DEBUG[9447] devicestate.c: Changing state for Local/s@voipstation - state 2 (In use)
Jun 14 10:28:48 DEBUG[9447] devicestate.c: Changing state for Local/s@voipstation - state 2 (In use)
Jun 14 10:28:48 DEBUG[9447] devicestate.c: Changing state for CAPI/ISDN1/XXXXXXXXX - state 2 (In use)
Jun 14 10:28:48 DEBUG[9447] devicestate.c: Changing state for CAPI/ISDN1/XXXXXXXXX - state 2 (In use)
Jun 14 10:28:48 DEBUG[2888] app_queue.c: Device 'Local/s@voipstation' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jun 14 10:28:48 DEBUG[2889] app_queue.c: Device 'Local/s@voipstation' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jun 14 10:28:48 DEBUG[2891] app_queue.c: Device 'CAPI/ISDN1/XXXXXXXXX' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jun 14 10:28:48 DEBUG[2892] app_queue.c: Device 'CAPI/ISDN1/XXXXXXXXX' changed to state '2' (In use) but we don't care because they're not a member of any queue.
Jun 14 10:28:50 VERBOSE[2885] logger.c: -- CAPI/ISDN1/XXXXXXXXX-2a is making progress passing it to Local/s@voipstation-ceb4,1
Jun 14 10:29:01 VERBOSE[9446] logger.c: -- Remote UNIX connection
Jun 14 10:29:01 VERBOSE[2924] logger.c: -- Remote UNIX connection disconnected
Jun 14 10:29:02 VERBOSE[9446] logger.c: -- Remote UNIX connection
Jun 14 10:29:02 VERBOSE[2934] logger.c: -- Remote UNIX connection disconnected
Jun 14 10:29:02 VERBOSE[9446] logger.c: -- Remote UNIX connection
Jun 14 10:29:02 VERBOSE[2937] logger.c: -- Remote UNIX connection disconnected
Jun 14 10:29:02 VERBOSE[9446] logger.c: -- Remote UNIX connection
Jun 14 10:29:02 VERBOSE[2948] logger.c: -- Remote UNIX connection disconnected
Jun 14 10:29:03 VERBOSE[2885] logger.c: -- CAPI/ISDN1/XXXXXXXXX-2a is ringing
Jun 14 10:29:04 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:04 DEBUG[9456] acl.c: ##### Testing 192.168.78.254 with 192.168.78.0
Jun 14 10:29:04 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as76fc0480
Jun 14 10:29:04 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:05 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:05 DEBUG[9456] acl.c: ##### Testing 192.168.78.36 with 192.168.78.0
Jun 14 10:29:05 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as432167f0
Jun 14 10:29:05 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:05 DEBUG[9447] devicestate.c: Changing state for CAPI/ISDN1/XXXXXXXXX - state 2 (In use)
Jun 14 10:29:05 VERBOSE[2885] logger.c: -- CAPI/ISDN1/XXXXXXXXX-2a answered Local/s@voipstation-ceb4,1
Jun 14 10:29:05 DEBUG[2885] channel.c: Dropping duplicate answer!
Jun 14 10:29:05 DEBUG[2957] app_queue.c: Device 'CAPI/ISDN1/XXXXXXXXX' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[B]Jun 14 10:29:09 DTMF[2885] channel.c: Local/s@voipstation-ceb4,1 : 8
Jun 14 10:29:10 DTMF[2885] channel.c: Local/s@voipstation-ceb4,1 : 5
Jun 14 10:29:11 DTMF[2885] channel.c: Local/s@voipstation-ceb4,1 : 4
[/B]Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:12 DEBUG[9456] acl.c: ##### Testing 85.214.61.130 with 192.168.78.0
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Target address 85.214.61.130 is not local, substituting externip
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7998bb0c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as02371d10
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7ac1d29e
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as08d00413
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as5347953c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7998bb0c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as02371d10
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7ac1d29e
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as08d00413
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7998bb0c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as02371d10
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as7ac1d29e
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as7998bb0c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as02371d10
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = No match Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as7998bb0c
Jun 14 10:29:12 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:13 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as5fb1bc56
Jun 14 10:29:13 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
[B]Jun 14 10:29:13 DTMF[2885] channel.c: Local/s@voipstation-ceb4,1 : #
Jun 14 10:29:13 VERBOSE[2886] logger.c: -- User entered '854'[/B]
Jun 14 10:29:13 DEBUG[2886] pbx.c: Launching 'NoOp'
Jun 14 10:29:13 VERBOSE[2886] logger.c: -- Executing NoOp("Local/s@voipstation-ceb4,2", "854") in new stack
Jun 14 10:29:13 DEBUG[2886] pbx.c: Launching 'Hangup'
Jun 14 10:29:13 VERBOSE[2886] logger.c: -- Executing Hangup("Local/s@voipstation-ceb4,2", "") in new stack
Jun 14 10:29:13 DEBUG[2886] pbx.c: Spawn extension (voipstation,s,4) exited non-zero on 'Local/s@voipstation-ceb4,2'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 's'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 'voipstation'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 'Local/s@voipstation-ceb4,2'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 'Hangup'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '2007-06-14 10:28:48'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '2007-06-14 10:28:48'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '2007-06-14 10:29:13'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '25'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '25'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 'ANSWERED'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is 'DOCUMENTATION'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '1181816928.276'
Jun 14 10:29:13 DEBUG[2886] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2886] channel.c: Hanging up channel 'Local/s@voipstation-ceb4,2'
Jun 14 10:29:13 DEBUG[2885] channel.c: Didn't get a frame from channel: Local/s@voipstation-ceb4,1
Jun 14 10:29:13 DEBUG[2885] channel.c: Bridge stops bridging channels Local/s@voipstation-ceb4,1 and CAPI/ISDN1/XXXXXXXXX-2a
Jun 14 10:29:13 DEBUG[2885] channel.c: Hanging up channel 'CAPI/ISDN1/XXXXXXXXX-2a'
Jun 14 10:29:13 DEBUG[2885] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jun 14 10:29:13 DEBUG[2885] pbx.c: Spawn extension (plain-capi-out,s,4) exited non-zero on 'Local/s@voipstation-ceb4,1'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 's'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'plain-capi-out'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'Local/s@voipstation-ceb4,1'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'CAPI/ISDN1/XXXXXXXXX-2a'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'Dial'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'CAPI/ISDN1/:XXXXXXXXX||H'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '2007-06-14 10:28:48'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '2007-06-14 10:29:05'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '2007-06-14 10:29:13'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '25'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '8'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'ANSWERED'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is 'DOCUMENTATION'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '1181816928.275'
Jun 14 10:29:13 DEBUG[2885] pbx.c: Function result is '(null)'
Jun 14 10:29:13 DEBUG[2885] channel.c: Hanging up channel 'Local/s@voipstation-ceb4,1'
Jun 14 10:29:13 NOTICE[2885] pbx_spool.c: Call completed to LOCAL/s@voipstation
Jun 14 10:29:13 DEBUG[9447] devicestate.c: Changing state for Local/s@voipstation - state 0 (Unknown)
Jun 14 10:29:13 DEBUG[9447] devicestate.c: Changing state for CAPI/ISDN1/XXXXXXXXX - state 1 (Not in use)
Jun 14 10:29:13 DEBUG[9447] devicestate.c: Changing state for CAPI/ISDN1/XXXXXXXXX - state 1 (Not in use)
Jun 14 10:29:13 DEBUG[9447] devicestate.c: Changing state for Local/s@voipstation - state 0 (Unknown)
Jun 14 10:29:13 DEBUG[2972] app_queue.c: Device 'Local/s@voipstation' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Jun 14 10:29:13 DEBUG[2973] app_queue.c: Device 'CAPI/ISDN1/XXXXXXXXX' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jun 14 10:29:13 DEBUG[2974] app_queue.c: Device 'CAPI/ISDN1/XXXXXXXXX' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jun 14 10:29:13 DEBUG[2975] app_queue.c: Device 'Local/s@voipstation' changed to state '0' (Unknown) but we don't care because they're not a member of any queue.
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:16 DEBUG[9456] acl.c: ##### Testing 192.168.78.3 with 192.168.78.0
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as2da32167
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:16 DEBUG[9456] acl.c: ##### Testing 192.168.78.3 with 192.168.78.0
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as63dacbb7
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:16 DEBUG[9456] acl.c: ##### Testing 192.168.78.3 with 192.168.78.0
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as1a460a59
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
Jun 14 10:29:16 DEBUG[9456] acl.c: ##### Testing 192.168.78.3 with 192.168.78.0
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: = Found Their Call ID: [email protected] Their Tag Our tag: as58a8682a
Jun 14 10:29:16 DEBUG[9456] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found