[Asterisk-Users] Asterisk not waiting for E&M Wink (I think)

Derek derek at allinternetadvertising.com
Wed Jun 7 08:24:21 MST 2006


Hi All,

I have a rather peculiar problem. Whenever I dial out over ZAP/g0 the 
phone will just ring and ring, even if I answer the phone on the other 
end. Whats strange is that the * phone will continue to ring even after 
I've answered and (sometimes) hung up the dialed phone. If I make an 
extension to just directly dial out on ZAP/1, its almost the same 
behavior, it will continue to ring, but it will connect the call and 
continue to ring. Its strange. I saw this over at digiums bug tracking 
database 
http://bugs.digium.com/bug_view_advanced_page.php?bug_id=3772&history=1 
and I think thats my issue, but the ticket is quite old and I would've 
thought they would've fixed whatever was causing it by now. I'll attach 
configs and a snip of the logs. Anyone know how to fix this? (BTW, this 
is not a PRI or BRI I am connecting to). Also, I've tested this using 
Xten Lite and a Linksys PAP2 device, with the same results. (Both SIP)

Any help would be appreciated,
Derek

zaptel.conf:
span=1,1,0,esf,b8zs
e&m=1-24
loadzone = us
defaultzone=us

zapata.conf:
[channels]
language=en
context=from-pstn
signalling = em_w
rxgain=2
group = 0
channel => 1-24

/var/log/asterisk/full (snip):
Jun  7 08:15:09 DEBUG[14754] channel.c: Not copying variable SIPURI.
Jun  7 08:15:09 DEBUG[14758] app_queue.c: Device 'Zap/1' changed to 
state '2' (In use) but we don't care because they're not a member of any 
queue.
Jun  7 08:15:09 DEBUG[14754] chan_zap.c: Dialing '(snipped)'
Jun  7 08:15:09 DEBUG[14754] chan_zap.c: Deferring dialing...
Jun  7 08:15:09 DEBUG[13721] channel.c: Avoiding initial deadlock for 
'Zap/1-1'
Jun  7 08:15:09 VERBOSE[14754] logger.c:     -- Called g0/(snipped)
Jun  7 08:15:09 DEBUG[13721] devicestate.c: Changing state for Zap/1 - 
state 2 (In use)
Jun  7 08:15:09 DEBUG[14759] app_queue.c: Device 'Zap/1' changed to 
state '2' (In use) but we don't care because they're not a member of any 
queue.
Jun  7 08:15:10 DEBUG[14754] chan_zap.c: Exception on 18, channel 1
Jun  7 08:15:10 DEBUG[14754] chan_zap.c: Got event Wink/Flash(3) on 
channel 1 (index 0)
Jun  7 08:15:10 DEBUG[14754] chan_zap.c: Ignoring wink on channel 1
Jun  7 08:15:10 DEBUG[14754] chan_zap.c: Exception on 18, channel 1
Jun  7 08:15:10 DEBUG[14754] chan_zap.c: Got event Hook Transition 
Complete(12) on channel 1 (index 0)
Jun  7 08:15:12 DEBUG[14754] chan_zap.c: Exception on 18, channel 1
Jun  7 08:15:12 DEBUG[14754] chan_zap.c: Got event Dial Complete(9) on 
channel 1 (index 0)
Jun  7 08:15:12 DEBUG[14754] chan_zap.c: No echo cancellation requested
Jun  7 08:15:12 DEBUG[13721] channel.c: Avoiding initial deadlock for 
'Zap/1-1'
Jun  7 08:15:12 DEBUG[13721] devicestate.c: Changing state for Zap/1 - 
state 6 (Ringing)
Jun  7 08:15:12 DEBUG[14760] app_queue.c: Device 'Zap/1' changed to 
state '6' (Ringing) but we don't care because they're not a member of 
any queue.
Jun  7 08:15:25 DEBUG[13726] chan_sip.c: = Found Their Call ID: 
9718f1cb-9adb2b38 at 192.168.1.212 Their Tag dee5f8aff7d531a4o0 Our tag: 
as61f0f08a
Jun  7 08:15:25 DEBUG[13726] chan_sip.c: **** Received CANCEL (14) - 
Command in SIP CANCEL
Jun  7 08:15:25 DEBUG[14754] channel.c: Hanging up channel 'Zap/1-1'
Jun  7 08:15:25 DEBUG[14754] chan_zap.c: zt_hangup(Zap/1-1)
Jun  7 08:15:25 DEBUG[14754] chan_zap.c: Hangup: channel: 1 index = 0, 
normal = 18, callwait = -1, thirdcall = -1
Jun  7 08:15:25 DEBUG[14754] chan_zap.c: Set option TDD MODE, value: 
OFF(0) on Zap/1-1
Jun  7 08:15:25 DEBUG[14754] chan_zap.c: Updated conferencing on 1, with 
0 conference users
Jun  7 08:15:25 VERBOSE[14754] logger.c:     -- Hungup 'Zap/1-1'
Jun  7 08:15:25 DEBUG[14754] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Jun  7 08:15:25 DEBUG[14754] app_macro.c: Spawn extension 
(macro-dialout-trunk,s,14) exited non-zero on 'SIP/1040-45d7' in macro 
'dialout-trunk'
Jun  7 08:15:25 DEBUG[13721] devicestate.c: Changing state for Zap/1 - 
state 0 (Unknown)
Jun  7 08:15:25 DEBUG[14754] pbx.c: Spawn extension 
(macro-dialout-trunk,s,14) exited non-zero on 'SIP/1040-45d7'
Jun  7 08:15:25 DEBUG[14761] app_queue.c: Device 'Zap/1' changed to 
state '0' (Unknown) but we don't care because they're not a member of 
any queue.
Jun  7 08:15:25 DEBUG[14754] cdr_addon_mysql.c: cdr_mysql: inserting a 
CDR record.
Jun  7 08:15:25 DEBUG[14754] 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 ('2006-06-07 08:15:09','\"Vonage\" 
<1040>','1040','9(snipped)','from-internal', 
'SIP/1040-45d7','Zap/1-1','Dial','ZAP/g0/(snipped)120|r',16,0,'NO 
ANSWER',3,'','1149693309.30')
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '"Vonage" <1040>'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '1040'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '(snipped)'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'from-internal'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'SIP/1040-45d7'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'Zap/1-1'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'Dial'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 
'ZAP/g0/(snipped)|120|r'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '2006-06-07 08:15:09'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '(null)'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '2006-06-07 08:15:25'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '16'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '0'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'NO ANSWER'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is 'DOCUMENTATION'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '(null)'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '1149693309.30'
Jun  7 08:15:25 DEBUG[14754] pbx.c: Function result is '(null)'
Jun  7 08:15:25 DEBUG[14754] channel.c: Hanging up channel 'SIP/1040-45d7'
Jun  7 08:15:25 DEBUG[14754] chan_sip.c: Hangup call SIP/1040-45d7, SIP 
callid 9718f1cb-9adb2b38 at 192.168.1.212)
Jun  7 08:15:25 DEBUG[14754] chan_sip.c: update_call_counter(1040) - 
decrement call limit counter
Jun  7 08:15:25 DEBUG[14754] chan_sip.c: Updating call counter for 
incoming call
Jun  7 08:15:25 DEBUG[13721] chan_sip.c: Checking device state for peer 1040
Jun  7 08:15:25 DEBUG[13721] devicestate.c: Changing state for SIP/1040 
- state 1 (Not in use)
Jun  7 08:15:25 DEBUG[14762] app_queue.c: Device 'SIP/1040' changed to 
state '1' (Not in use) but we don't care because they're not a member of 
any queue.
Jun  7 08:15:25 DEBUG[13721] chan_sip.c: Checking device state for peer 1040
Jun  7 08:15:25 DEBUG[13726] chan_sip.c: = Found Their Call ID: 
9718f1cb-9adb2b38 at 192.168.1.212 Their Tag dee5f8aff7d531a4o0 Our tag: 
as61f0f08a
Jun  7 08:15:25 DEBUG[13726] chan_sip.c: **** Received ACK (6) - Command 
in SIP ACK
Jun  7 08:15:25 DEBUG[13726] chan_sip.c: Stopping retransmission on 
'9718f1cb-9adb2b38 at 192.168.1.212' of Response 102: Match Found
Jun  7 08:15:34 VERBOSE[14752] logger.c:     -- Remote UNIX connection 
disconnected



-- 
Derek Fedel





More information about the asterisk-users mailing list