Re: [Asterisk-Users] False Zap answer problem (Again)
I've reported this issue as a bug, and learned that a workaround seems to be disabling callwaiting :(. Since callwaiting was quite helpful on my systems, I'm not happy with this. Anyone interested can go to issue tracer and follow if a fix will be released soon (ID# 0005188). I really tend to think that there is a bug in chan_zap.c, because this issue happens only when the first caller hangs up first, never the otherwise. I mean if the second caller hangs up first, the first caller continues as usual without any problems and reaches to the VoiceMail system as expected. Please see below, in this case there is no problem at all: -- Executing Dial(SIP/201-e848, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-1 is ringing -- Executing Dial(SIP/202-c185, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-2 is ringing -- Zap/1-1 is ringing -- CPE does not support Call Waiting Caller*ID. -- Hungup 'Zap/1-2' == Spawn extension (from-internal, 200, 1) exited non-zero on 'SIP/202-c185' -- Zap/1-1 is ringing -- Zap/1-1 is ringing -- Nobody picked up in 15000 ms -- Hungup 'Zap/1-1' -- Executing VoiceMail(SIP/201-e848, [EMAIL PROTECTED]) in new stack etc. Please see below example for the problem case where the second caller cannot reach at VoiceMail system, but hears ringing indefinately, thus the problem. This cannot be the expected behaviour. I was suspicious about Call Waiting Caller*ID, so I disabled it, but nothing changes. Still, I am concerned about it, because the problem happens to the Call Waiting (i.e. the second) caller (I mean to the caller who causes the Call Waiting for the callee). What's going on here? Can somebody try and comment please? Any ideas? Thanks, Soner I can replicate this issue on my test system with 1x FXS module too: -- Executing Dial(SIP/202-ea85, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-1 is ringing -- Zap/1-1 is ringing -- Executing Dial(SIP/201-bf73, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-2 is ringing -- CPE does not support Call Waiting Caller*ID. -- Zap/1-1 is ringing -- Hungup 'Zap/1-1' == Spawn extension (from-internal, 200, 1) exited non-zero on 'SIP/202-ea85' -- Zap/1-2 answered SIP/201-bf73 When the channels are internal as they are above, it looks like a nonissue and seems like an expected behaviour. But if the call is from external (FXO lines), hangup detection using busy detect is affected, and my PSTN lines stay open and Asterisk keeps attempting to bridge the 2 channels (FXO and FXS). Can somebody comment please? Should this be the expected behaviour of chan_zap? Soner I've been monitoring this problem for almost a month now. I realized that it is more extensive than what I described previously. I can very easily replicate this problem on every Zap channel. Following is the senario: 1. Call Zap/5 via say SIP/15 - Zap/5-1 created and starts to ring 2. Call Zap/5 via say SIP/21 - Zap/5-2 created and starts to ring 3. Hangup SIP/15 - Zap/5-1 hungup Right after this point we have the problem (please see full log below for details): Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-2 answered SIP/21-efcb When in fact nobody is answering Zap/5-2 !!! And on SIP/21 I hear strange ringing tone indefinetly, untill I hangup SIP/21. What the hell is going on here? I don't have any other problem, this system is in use for 1.5 month now (Users cannot notice it, because they hangup immediately). Since I can replicate this problem with Zap/6 and Zap/7 also, I tend to think that this is not specific to any FXS module. But, of course, it could be the TDM PCI card itself. Could this be a bug in chan_zap.c? Can somebody please confirm that using the same senario this only happens on my system with my TDM card, so I don't file a bug report? Please find below the relevant sections of full log and my previous post, Thanks, Soner Sep 10 19:22:33 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 15 Sep 10 19:22:33 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:51926 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Macro(SIP/15-f784, ichatarama|Zap/5|10) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing GotoIf(SIP/15-f784, =1?200) in new stack Sep 10 19:22:33 DEBUG[27367] pbx.c: Not taking any branch Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Dial(SIP/15-f784, Zap/5|24|rTtWw) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Called 5 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing Sep 10 19:22:34 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 21 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:46209 Sep 10 19:22:35
[Asterisk-Users] False Zap answer problem (Again)
I've been monitoring this problem for almost a month now. I realized that it
is more extensive than what I described previously. I can very easily
replicate this problem on every Zap channel. Following is the senario:
1. Call Zap/5 via say SIP/15 -
Zap/5-1 created and starts to ring
2. Call Zap/5 via say SIP/21 -
Zap/5-2 created and starts to ring
3. Hangup SIP/15 -
Zap/5-1 hungup
Right after this point we have the problem (please see full log below for
details):
Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-2 answered SIP/21-efcb
When in fact nobody is answering Zap/5-2 !!! And on SIP/21 I hear strange
ringing tone indefinetly, untill I hangup SIP/21.
What the hell is going on here? I don't have any other problem, this system
is in use for 1.5 month now (Users cannot notice it, because they hangup
immediately).
Since I can replicate this problem with Zap/6 and Zap/7 also, I tend to
think that this is not specific to any FXS module. But, of course, it could
be the TDM PCI card itself. Could this be a bug in chan_zap.c?
Can somebody please confirm that using the same senario this only happens on
my system with my TDM card, so I don't file a bug report?
Please find below the relevant sections of full log and my previous post,
Thanks,
Soner
Sep 10 19:22:33 DEBUG[27367] chan_sip.c: Checking SIP call limits for device
15
Sep 10 19:22:33 DEBUG[27367] chan_sip.c: build_route: Contact hop:
sip:[EMAIL PROTECTED]:51926
Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing
Macro(SIP/15-f784, ichatarama|Zap/5|10) in new stack
Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing
GotoIf(SIP/15-f784, =1?200) in new stack
Sep 10 19:22:33 DEBUG[27367] pbx.c: Not taking any branch
Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing
Dial(SIP/15-f784, Zap/5|24|rTtWw) in new stack
Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Called 5
Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing
Sep 10 19:22:34 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288
Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288
Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Checking SIP call limits for device
21
Sep 10 19:22:35 DEBUG[27367] chan_sip.c: build_route: Contact hop:
sip:[EMAIL PROTECTED]:46209
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing
Macro(SIP/21-efcb, ichatarama|Zap/5|10) in new stack
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing
GotoIf(SIP/21-efcb, =1?200) in new stack
Sep 10 19:22:35 DEBUG[27367] pbx.c: Not taking any branch
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing
Dial(SIP/21-efcb, Zap/5|24|rTtWw) in new stack
Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Already have a dsp on Zap/5-2?
Sep 10 19:22:35 WARNING[27367] chan_zap.c: Spill already exists?!?
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Called 5
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Zap/5-2 is ringing
Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Exception on 11, channel 5
Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Got event Ringer Off(11) on channel
5 (index 0)
Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing
Sep 10 19:22:36 VERBOSE[27367] logger.c: -- CPE does not support Call
Waiting Caller*ID.
Sep 10 19:22:39 DEBUG[27367] chan_zap.c: Exception on 11, channel 5
Sep 10 19:22:39 DEBUG[27367] chan_zap.c: Got event Ringer On(10) on channel
5 (index 0)
Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Exception on 11, channel 5
Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Got event Ringer Off(11) on channel
5 (index 0)
Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing
Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Hangup: channel: 5 index = 0,
normal = 11, callwait = 35, thirdcall = -1
Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Swapping 1 and 0
Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Released sub 1 of channel 5
Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Hungup 'Zap/5-1'
Sep 10 19:22:41 DEBUG[27367] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Sep 10 19:22:41 VERBOSE[27367] logger.c: == Spawn extension
(macro-ichatarama, s, 2) exited non-zero on 'SIP/15-f784' in macro
'ichatarama'
Sep 10 19:22:41 VERBOSE[27367] logger.c: == Spawn extension (ichat, 19, 1)
exited non-zero on 'SIP/15-f784'
Sep 10 19:22:41 DEBUG[27367] cdr_addon_mysql.c: cdr_mysql: inserting a CDR
record.
Sep 10 19:22:41 DEBUG[27367] 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 ('2005-09-10 19:22:33','\Ichat\ 15','15','19','ichat',
'SIP/15-f784','Zap/5-1','Dial','Zap/5|24|rTtWw',8,0,'NO
ANSWER',3,'','1126369353.4')
Sep 10 19:22:41 DEBUG[27367] chan_sip.c: update_user_counter(15) - decrement
inUse counter
Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-2 answered SIP/21-efcb
Sep 10 19:22:45 DEBUG[27367] chan_zap.c: Exception on 11, channel 5
Sep 10 19:22:45
Re: [Asterisk-Users] False Zap answer problem (Again)
I can replicate this issue on my test system with 1x FXS module too: -- Executing Dial(SIP/202-ea85, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-1 is ringing -- Zap/1-1 is ringing -- Executing Dial(SIP/201-bf73, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-2 is ringing -- CPE does not support Call Waiting Caller*ID. -- Zap/1-1 is ringing -- Hungup 'Zap/1-1' == Spawn extension (from-internal, 200, 1) exited non-zero on 'SIP/202-ea85' -- Zap/1-2 answered SIP/201-bf73 When the channels are internal as they are above, it looks like a nonissue and seems like an expected behaviour. But if the call is from external (FXO lines), hangup detection using busy detect is affected, and my PSTN lines stay open and Asterisk keeps attempting to bridge the 2 channels (FXO and FXS). Can somebody comment please? Should this be the expected behaviour of chan_zap? Soner I've been monitoring this problem for almost a month now. I realized that it is more extensive than what I described previously. I can very easily replicate this problem on every Zap channel. Following is the senario: 1. Call Zap/5 via say SIP/15 - Zap/5-1 created and starts to ring 2. Call Zap/5 via say SIP/21 - Zap/5-2 created and starts to ring 3. Hangup SIP/15 - Zap/5-1 hungup Right after this point we have the problem (please see full log below for details): Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-2 answered SIP/21-efcb When in fact nobody is answering Zap/5-2 !!! And on SIP/21 I hear strange ringing tone indefinetly, untill I hangup SIP/21. What the hell is going on here? I don't have any other problem, this system is in use for 1.5 month now (Users cannot notice it, because they hangup immediately). Since I can replicate this problem with Zap/6 and Zap/7 also, I tend to think that this is not specific to any FXS module. But, of course, it could be the TDM PCI card itself. Could this be a bug in chan_zap.c? Can somebody please confirm that using the same senario this only happens on my system with my TDM card, so I don't file a bug report? Please find below the relevant sections of full log and my previous post, Thanks, Soner Sep 10 19:22:33 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 15 Sep 10 19:22:33 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:51926 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Macro(SIP/15-f784, ichatarama|Zap/5|10) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing GotoIf(SIP/15-f784, =1?200) in new stack Sep 10 19:22:33 DEBUG[27367] pbx.c: Not taking any branch Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Dial(SIP/15-f784, Zap/5|24|rTtWw) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Called 5 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing Sep 10 19:22:34 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 21 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:46209 Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing Macro(SIP/21-efcb, ichatarama|Zap/5|10) in new stack Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing GotoIf(SIP/21-efcb, =1?200) in new stack Sep 10 19:22:35 DEBUG[27367] pbx.c: Not taking any branch Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing Dial(SIP/21-efcb, Zap/5|24|rTtWw) in new stack Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Already have a dsp on Zap/5-2? Sep 10 19:22:35 WARNING[27367] chan_zap.c: Spill already exists?!? Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Called 5 Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Zap/5-2 is ringing Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Exception on 11, channel 5 Sep 10 19:22:35 DEBUG[27367] chan_zap.c: Got event Ringer Off(11) on channel 5 (index 0) Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing Sep 10 19:22:36 VERBOSE[27367] logger.c: -- CPE does not support Call Waiting Caller*ID. Sep 10 19:22:39 DEBUG[27367] chan_zap.c: Exception on 11, channel 5 Sep 10 19:22:39 DEBUG[27367] chan_zap.c: Got event Ringer On(10) on channel 5 (index 0) Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Exception on 11, channel 5 Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Got event Ringer Off(11) on channel 5 (index 0) Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Hangup: channel: 5 index = 0, normal = 11, callwait = 35, thirdcall = -1 Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Swapping 1 and 0 Sep 10 19:22:41 DEBUG[27367] chan_zap.c: Released sub 1 of channel 5 Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Hungup 'Zap/5-1' Sep 10 19:22:41 DEBUG[27367] app_dial.c: Exiting with DIALSTATUS=CANCEL. Sep 10 19:22:41 VERBOSE[27367] logger.c: == Spawn extension
Re: [Asterisk-Users] False Zap answer problem (Again)
I really tend to think that there is a bug in chan_zap.c, because this issue happens only when the first caller hangs up first, never the otherwise. I mean if the second caller hangs up first, the first caller continues as usual without any problems and reaches to the VoiceMail system as expected. Please see below, in this case there is no problem at all: -- Executing Dial(SIP/201-e848, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-1 is ringing -- Executing Dial(SIP/202-c185, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-2 is ringing -- Zap/1-1 is ringing -- CPE does not support Call Waiting Caller*ID. -- Hungup 'Zap/1-2' == Spawn extension (from-internal, 200, 1) exited non-zero on 'SIP/202-c185' -- Zap/1-1 is ringing -- Zap/1-1 is ringing -- Nobody picked up in 15000 ms -- Hungup 'Zap/1-1' -- Executing VoiceMail(SIP/201-e848, [EMAIL PROTECTED]) in new stack etc. Please see below example for the problem case where the second caller cannot reach at VoiceMail system, but hears ringing indefinately, thus the problem. This cannot be the expected behaviour. I was suspicious about Call Waiting Caller*ID, so I disabled it, but nothing changes. Still, I am concerned about it, because the problem happens to the Call Waiting (i.e. the second) caller (I mean to the caller who causes the Call Waiting for the callee). What's going on here? Can somebody try and comment please? Any ideas? Thanks, Soner I can replicate this issue on my test system with 1x FXS module too: -- Executing Dial(SIP/202-ea85, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-1 is ringing -- Zap/1-1 is ringing -- Executing Dial(SIP/201-bf73, ZAP/1|15|tr) in new stack -- Called 1 -- Zap/1-2 is ringing -- CPE does not support Call Waiting Caller*ID. -- Zap/1-1 is ringing -- Hungup 'Zap/1-1' == Spawn extension (from-internal, 200, 1) exited non-zero on 'SIP/202-ea85' -- Zap/1-2 answered SIP/201-bf73 When the channels are internal as they are above, it looks like a nonissue and seems like an expected behaviour. But if the call is from external (FXO lines), hangup detection using busy detect is affected, and my PSTN lines stay open and Asterisk keeps attempting to bridge the 2 channels (FXO and FXS). Can somebody comment please? Should this be the expected behaviour of chan_zap? Soner I've been monitoring this problem for almost a month now. I realized that it is more extensive than what I described previously. I can very easily replicate this problem on every Zap channel. Following is the senario: 1. Call Zap/5 via say SIP/15 - Zap/5-1 created and starts to ring 2. Call Zap/5 via say SIP/21 - Zap/5-2 created and starts to ring 3. Hangup SIP/15 - Zap/5-1 hungup Right after this point we have the problem (please see full log below for details): Sep 10 19:22:41 VERBOSE[27367] logger.c: -- Zap/5-2 answered SIP/21-efcb When in fact nobody is answering Zap/5-2 !!! And on SIP/21 I hear strange ringing tone indefinetly, untill I hangup SIP/21. What the hell is going on here? I don't have any other problem, this system is in use for 1.5 month now (Users cannot notice it, because they hangup immediately). Since I can replicate this problem with Zap/6 and Zap/7 also, I tend to think that this is not specific to any FXS module. But, of course, it could be the TDM PCI card itself. Could this be a bug in chan_zap.c? Can somebody please confirm that using the same senario this only happens on my system with my TDM card, so I don't file a bug report? Please find below the relevant sections of full log and my previous post, Thanks, Soner Sep 10 19:22:33 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 15 Sep 10 19:22:33 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:51926 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Macro(SIP/15-f784, ichatarama|Zap/5|10) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing GotoIf(SIP/15-f784, =1?200) in new stack Sep 10 19:22:33 DEBUG[27367] pbx.c: Not taking any branch Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Executing Dial(SIP/15-f784, Zap/5|24|rTtWw) in new stack Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Called 5 Sep 10 19:22:33 VERBOSE[27367] logger.c: -- Zap/5-1 is ringing Sep 10 19:22:34 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Setting NAT on RTP to 524288 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: Checking SIP call limits for device 21 Sep 10 19:22:35 DEBUG[27367] chan_sip.c: build_route: Contact hop: sip:[EMAIL PROTECTED]:46209 Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing Macro(SIP/21-efcb, ichatarama|Zap/5|10) in new stack Sep 10 19:22:35 VERBOSE[27367] logger.c: -- Executing GotoIf(SIP/21-efcb, =1?200) in new stack Sep 10 19:22:35 DEBUG[27367] pbx.c: Not taking any branch Sep 10 19:22:35 VERBOSE[27367]
