<span class="postbody">Problem: <b style="COLOR: #ffa34f">Call</b> <b style="COLOR: #ffa34f">waiting</b> comes in, I press flash to answer it, and the first caller gets disconnected after 3 seconds. This is all ZAP - no VOIP.
<br><br>System: <br>Analog stations and trunks running on a pair of TDM400's. It does NOT have <b style="COLOR: #ffa34f">call</b> <b style="COLOR: #ffa34f">waiting</b> from the phone company, and I have enabled it in all my conf files. The trunks are set to FXSKS and the stations are FXOKS. I am not using
<b style="COLOR: #ffa34f">call</b> progress or busy detect. Also its * 1.2.13 w/ FreePBX2.2. I have scoured the net for this, and nobody seems to know.<br><br>Here is some logging from a <b style="COLOR: #ffa34f">call</b>
: <br><br>Feb 1 17:41:53 DEBUG[6765] chan_zap.c: Requested indication 3 on channel Zap/5-1 <br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Function result is 's'
<br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Function result is '5' <br>Feb 1 17:41:53 DEBUG[6765] db.c: Unable to find key '5187152626' in family 'blacklist'
<br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Expression result is '0' <br>Feb 1 17:41:53 DEBUG[6765] pbx.c: Not taking any branch <br>Feb 1 17:41:53 DEBUG[6765] chan_zap.c: Took Zap/5-1 off hook <br>Feb 1 17:41:53 DEBUG[6765] chan_zap.c: Enabled echo cancellation on channel 5
<br>Feb 1 17:41:53 DEBUG[6765] chan_zap.c: Engaged echo training on channel 5 <br>Feb 1 17:41:54 DEBUG[6765] channel.c: Scheduling timer at 160 sample intervals <br>Feb 1 17:42:00 DEBUG[6765] chan_zap.c: DTMF digit: 5 on Zap/5-1
<br>Feb 1 17:42:00 DEBUG[6765] channel.c: Scheduling timer at 0 sample intervals <br>Feb 1 17:42:00 DEBUG[6765] pbx.c: Oooh, got something to jump out with ('5')! <br>Feb 1 17:42:01 DEBUG[6765] chan_zap.c: DTMF digit: 0 on Zap/5-1
<br>Feb 1 17:42:02 DEBUG[6765] chan_zap.c: DTMF digit: 0 on Zap/5-1 <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '5187152626' <br>Feb 1 17:42:02 DEBUG[6765]
pbx.c: Expression result is '0' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Not taking any branch <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '0' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Not taking any branch
<br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '5187152626' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '5187152626/user' in family 'DEVICE' <br>Feb 1 17:42:02 DEBUG[6765] func_db.c: DB: DEVICE/5187152626/user not found in database.
<br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '/cidname' in family 'AMPUSER' <br>Feb 1 17:42:02 DEBUG[6765] func_db.c: DB: AMPUSER//cidname not found in database.
<br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '0' <br>Feb 1 17:42:02 DEBUG[6765]
pbx.c: Not taking any branch <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '-1' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '64'
<br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '"" <5187152626>' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '500' in family 'CFU'
<br>Feb 1 17:42:02 DEBUG[6765] func_db.c: DB: CFU/500 not found in database. <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:02 DEBUG[6765]
pbx.c: Expression result is '0' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '15' <br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Function result is '0'
<br>Feb 1 17:42:02 DEBUG[6765] pbx.c: Expression result is '0' <br>Feb 1 17:42:02 VERBOSE[6765] logger.c: recordingcheck|20070201-174202|1170380512.151: Inbound recording enabled. <br>Feb 1 17:42:02 VERBOSE[6765]
logger.c: recordingcheck|20070201-174202|1170380512.151: CALLFILENAME=20070201-174202-1170380512.151 <br>Feb 1 17:42:02 DEBUG[6765] channel.c: Spy MixMonitor added to channel Zap/5-1 <br>Feb 1 17:42:02 VERBOSE[6765] logger.c
: dialparties.agi: Starting New Dialparties.agi <br>Feb 1 17:42:02 VERBOSE[6765] logger.c: dialparties.agi: priority is 1 <br>Feb 1 17:42:02 VERBOSE[6765] logger.c: dialparties.agi: Caller ID name is 'unknown' number is '5187152626'
<br>Feb 1 17:42:02 VERBOSE[6765] logger.c: dialparties.agi: Methodology of ring is 'none' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '500' in family 'CF' <br>Feb 1 17:42:02 DEBUG[6765]
db.c: Unable to find key '500' in family 'DND' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '500' in family 'CFB' <br>Feb 1 17:42:02 DEBUG[6765] db.c: Unable to find key '500' in family 'CFU'
<br>Feb 1 17:42:02 DEBUG[6765] chan_zap.c: Requested indication 3 on channel Zap/5-1 <br>Feb 1 17:42:02 DEBUG[6765] channel.c: Building translator from ulaw to SLINEAR for spies on channel Zap/5-1 <br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: Exception on 13, channel 2
<br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: Got event Ring/Answered(2) on channel 2 (index 0) <br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: Enabled echo cancellation on channel 2 <br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: Engaged echo training on channel 2
<br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: channel 2 answered <br>Feb 1 17:42:03 DEBUG[6765] chan_zap.c: Requested indication -1 on channel Zap/5-1 <br>Feb 1 17:42:23 NOTICE[6774] chan_zap.c: Got event 18 (Ring Begin)...
<br>Feb 1 17:42:25 NOTICE[6774] chan_zap.c: Got event 2 (Ring/Answered)... <br>Feb 1 17:42:25 DEBUG[6774] chan_zap.c: Requested indication 3 on channel Zap/6-1 <br>Feb 1 17:42:25 DEBUG[6774] pbx.c: Expression result is '1'
<br>Feb 1 17:42:25 DEBUG[6774] pbx.c: Function result is 's' <br>Feb 1 17:42:25 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:25 DEBUG[6774] pbx.c: Function result is '6' <br>Feb 1 17:42:25 DEBUG[6774]
pbx.c: Expression result is '0' <br>Feb 1 17:42:25 DEBUG[6774] pbx.c: Not taking any branch <br>Feb 1 17:42:25 DEBUG[6774] chan_zap.c: Took Zap/6-1 off hook <br>Feb 1 17:42:25 DEBUG[6774] chan_zap.c: Enabled echo cancellation on channel 6
<br>Feb 1 17:42:25 DEBUG[6774] chan_zap.c: Engaged echo training on channel 6 <br>Feb 1 17:42:28 DEBUG[6774] channel.c: Scheduling timer at 160 sample intervals <br>Feb 1 17:42:32 DEBUG[6774] chan_zap.c: DTMF digit: 5 on Zap/6-1
<br>Feb 1 17:42:32 DEBUG[6774] channel.c: Scheduling timer at 0 sample intervals <br>Feb 1 17:42:32 DEBUG[6774] pbx.c: Oooh, got something to jump out with ('5')! <br>Feb 1 17:42:32 DEBUG[6774] chan_zap.c: DTMF digit: 0 on Zap/6-1
<br>Feb 1 17:42:33 DEBUG[6774] chan_zap.c: DTMF digit: 0 on Zap/6-1 <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774]
pbx.c: Expression result is '0' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Not taking any branch <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '0' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Not taking any branch
<br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '/user' in family 'DEVICE' <br>Feb 1 17:42:33 DEBUG[6774] func_db.c: DB: DEVICE//user not found in database.
<br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '/cidname' in family 'AMPUSER' <br>Feb 1 17:42:33 DEBUG[6774] func_db.c: DB: AMPUSER//cidname not found in database.
<br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '0' <br>Feb 1 17:42:33 DEBUG[6774]
pbx.c: Not taking any branch <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '-1' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '64'
<br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '"" <>' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '500' in family 'CFU'
<br>Feb 1 17:42:33 DEBUG[6774] func_db.c: DB: CFU/500 not found in database. <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:33 DEBUG[6774]
pbx.c: Expression result is '0' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '15' <br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Function result is '0'
<br>Feb 1 17:42:33 DEBUG[6774] pbx.c: Expression result is '0' <br>Feb 1 17:42:33 VERBOSE[6774] logger.c: recordingcheck|20070201-174233|1170380539.153: Inbound recording enabled. <br>Feb 1 17:42:33 VERBOSE[6774]
logger.c: recordingcheck|20070201-174233|1170380539.153: CALLFILENAME=20070201-174233-1170380539.153 <br>Feb 1 17:42:33 DEBUG[6774] channel.c: Spy MixMonitor added to channel Zap/6-1 <br>Feb 1 17:42:33 VERBOSE[6774] logger.c
: dialparties.agi: Starting New Dialparties.agi <br>Feb 1 17:42:33 VERBOSE[6774] logger.c: dialparties.agi: priority is 1 <br>Feb 1 17:42:33 VERBOSE[6774] logger.c: dialparties.agi: Caller ID name is 'unknown' number is 'unknown'
<br>Feb 1 17:42:33 VERBOSE[6774] logger.c: dialparties.agi: Methodology of ring is 'none' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '500' in family 'CF' <br>Feb 1 17:42:33 DEBUG[6774]
db.c: Unable to find key '500' in family 'DND' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '500' in family 'CFB' <br>Feb 1 17:42:33 DEBUG[6774] db.c: Unable to find key '500' in family 'CFU'
<br>Feb 1 17:42:33 DEBUG[6774] chan_zap.c: Already have a dsp on Zap/2-2? <br>Feb 1 17:42:33 DEBUG[6774] chan_zap.c: Requested indication 3 on channel Zap/6-1 <br>Feb 1 17:42:33 DEBUG[6774] channel.c: Building translator from ulaw to SLINEAR for spies on channel Zap/6-1
<br>Feb 1 17:42:33 DEBUG[6765] chan_zap.c: DTMF digit: D on Zap/2-1 <br>Feb 1 17:42:33 DEBUG[6765] chan_zap.c: Got some DTMF, but it's for the CAS <br>Feb 1 17:42:35 DEBUG[6765] chan_zap.c: Exception on 13, channel 2
<br>Feb 1 17:42:35 DEBUG[6765] chan_zap.c: Got event On hook(1) on channel 2 (index 0) <br>Feb 1 17:42:35 DEBUG[6765] chan_zap.c: Swapping 1 and 0 <br>Feb 1 17:42:35 DEBUG[6765] chan_zap.c: Released sub 1 of channel 2 <br>
Feb 1 17:42:36 DEBUG[6765] chan_zap.c: disabled echo cancellation on channel 2 <br>Feb 1 17:42:36 DEBUG[6765] channel.c: Didn't get a frame from channel: Zap/2-1 <br>Feb 1 17:42:36 DEBUG[6765] channel.c: Bridge stops bridging channels Zap/5-1 and Zap/2-1
<br>Feb 1 17:42:36 DEBUG[6765] chan_zap.c: Hangup: channel: 2 index = -1, normal = 13, callwait = -1, thirdcall = -1 <br>Feb 1 17:42:36 DEBUG[6765] app_dial.c: Exiting with DIALSTATUS=ANSWER. <br>Feb 1 17:42:36 DEBUG[6774] chan_zap.c: Restoring owner of channel 2 on event 2
<br>Feb 1 17:42:36 DEBUG[6774] chan_zap.c: Requested indication -1 on channel Zap/6-1 <br>Feb 1 17:42:36 ERROR[6765] cdr_addon_mysql.c: cdr_mysql: cannot connect to database server localhost. CDR will not be spooled. <br>
Feb 1 17:42:36 DEBUG[6765] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. <br>Feb 1 17:42:36 DEBUG[6765] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-02-01 17:41:53','5187152626','5187152626','500','ivr-3', 'Zap/5-1','Zap/2-1','ResetCDR','w',43,43,'ANSWERED',3,'','
1170380512.151') <br>Feb 1 17:42:36 WARNING[6765] cdr.c: CDR on channel 'Zap/5-1' not posted <br>Feb 1 17:42:36 WARNING[6765] cdr.c: CDR on channel 'Zap/5-1' lacks end <br>Feb 1 17:42:36 DEBUG[6765] pbx.c
: Expression result is '1' <br>Feb 1 17:42:36 DEBUG[6765] pbx.c: Expression result is '1' <br>Feb 1 17:42:41 DEBUG[6765] channel.c: Spy MixMonitor removed from channel Zap/5-1 <br>Feb 1 17:42:41 DEBUG[6765] chan_zap.c: Hangup: channel: 5 index = 0, normal = 16, callwait = -1, thirdcall = -1
<br>Feb 1 17:42:41 DEBUG[6765] chan_zap.c: disabled echo cancellation on channel 5 <br>Feb 1 17:42:41 DEBUG[6765] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/5-1 <br>Feb 1 17:42:41 DEBUG[6765] chan_zap.c: Updated conferencing on 5, with 0 conference users
<br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Exception on 17, channel 6 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Got event On hook(1) on channel 6 (index 0) <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: disabled echo cancellation on channel 6
<br>Feb 1 17:43:11 DEBUG[6774] channel.c: Didn't get a frame from channel: Zap/6-1 <br>Feb 1 17:43:11 DEBUG[6774] channel.c: Bridge stops bridging channels Zap/6-1 and Zap/2-2 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Hangup: channel: 2 index = 0, normal = 13, callwait = -1, thirdcall = -1
<br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: disabled echo cancellation on channel 2 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-2 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Updated conferencing on 2, with 0 conference users
<br>Feb 1 17:43:11 DEBUG[6774] app_dial.c: Exiting with DIALSTATUS=ANSWER. <br>Feb 1 17:43:11 ERROR[6774] cdr_addon_mysql.c: cdr_mysql: cannot connect to database server localhost. CDR will not be spooled. <br>Feb 1 17:43:11 DEBUG[6774] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
<br>Feb 1 17:43:11 DEBUG[6774] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2007-02-01 17:42:25','','','500','ivr-3', 'Zap/6-1','Zap/2-2','ResetCDR','w',46,46,'ANSWERED',3,'','
1170380539.153') <br>Feb 1 17:43:11 WARNING[6774] cdr.c: CDR on channel 'Zap/6-1' not posted <br>Feb 1 17:43:11 WARNING[6774] cdr.c: CDR on channel 'Zap/6-1' lacks end <br>Feb 1 17:43:11 DEBUG[6774] pbx.c
: Expression result is '1' <br>Feb 1 17:43:11 DEBUG[6774] pbx.c: Expression result is '1' <br>Feb 1 17:43:11 DEBUG[6774] channel.c: Spy MixMonitor removed from channel Zap/6-1 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Hangup: channel: 6 index = 0, normal = 17, callwait = -1, thirdcall = -1
<br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: disabled echo cancellation on channel 6 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/6-1 <br>Feb 1 17:43:11 DEBUG[6774] chan_zap.c: Updated conferencing on 6, with 0 conference users
<br>Feb 1 17:43:12 WARNING[2797] chan_zap.c: zt hook failed: Device or resource busy <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: Exception on 13, channel 2 <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: Got event On hook(1) on channel 2 (index 0)
<br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: disabled echo cancellation on channel 2 <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: waitfordigit returned < 0... <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: Hangup: channel: 2 index = 0, normal = 13, callwait = -1, thirdcall = -1
<br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: disabled echo cancellation on channel 2 <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1 <br>Feb 1 17:43:14 DEBUG[6789] chan_zap.c: Updated conferencing on 2, with 0 conference users
<br>Feb 1 17:43:18 DEBUG[2797] chan_zap.c: Message status for 500@default changed from -1 to 1 on 2</span>