[asterisk-users] Phantom Calls

[Lee Jenkins]

Vadim Berezniker wrote:
> Enable verbose logging for the asterisk log
> Set verbose level to 4
> 
> Review the log file for anything that looks like a phantom call.
> There should be enough information to get some idea of why this is
> happening.
> 
> -----Original Message-----
> From: asterisk-users-bounces at lists.digium.com
> [mailto:asterisk-users-bounces at lists.digium.com] On Behalf Of Lee
> Jenkins
> Sent: Monday, June 18, 2007 1:56 PM
> To: Asterisk Users Mailing List - Non-Commercial Discussion
> Subject: Re: [asterisk-users] Phantom Calls
> 
> Stephen Bosch wrote:
>> Lee Jenkins wrote:
>>> I have a client that is having problems with phantom calls.  I have
> not 
>>> been able to see it happen myself, but they say when it happens, the 
>>> display on the phone (polycom 301's) says "Device" is calling, but
> when 
>>> they answer the phone, there is only silence and then they hang back
> up 
>>> and it sometimes rings again.
>>>
>>> I've been trying to track this down for a couple of weeks now with no
> 
>>> success yet.  If anyone can lend a suggestion or a pointer to look
> for, 
>>> I would greatly appreciate it.
>>>
>>> I've tried using WaitForRing() in case it is bad signaling coming
> from 
>>> the phone company.  But that has not helped.
> 

Below is the CLI output when this issue happened.  As you can see, I am 
using WaitForRing() to discourage phantom calls.  Every time this has 
happened, there appears to be an error getting caller ID.

I'm thinking that if I insert a Wait(1/2) before Answer, that may 
resolve the problems with Caller ID as it looks like Asterisk is not 
waiting long enough for the CID to come in.

Whether or not that will fix the problem with phantom calls remains to 
be seen after I make the changes.

Also notice, the line:
localhost*CLI>     -- Got SIP response 400 "Bad Request" back from 
192.168.1.216.

What does 400 Bad Request usually mean for sip?  Generic message or 
something that would provide a clue?

localhost*CLI>     -- Starting simple switch on 'Zap/3-1'
localhost*CLI> Jun 21 10:44:48 NOTICE[11257]: callerid.c:325 
callerid_feed: Caller*ID failed checksum
localhost*CLI> Jun 21 10:44:51 NOTICE[11257]: chan_zap.c:6233 ss_thread: 
Got event 18 (Ring Begin)...
localhost*CLI> Jun 21 10:44:53 NOTICE[11257]: chan_zap.c:6233 ss_thread: 
Got event 2 (Ring/Answered)...
     -- Executing WaitForRing("Zap/3-1", "1") in new stack
localhost*CLI>     -- Got a ring after the timeout
     -- Executing Answer("Zap/3-1", "") in new stack
     -- Executing Ringing("Zap/3-1", "") in new stack
     -- Executing SetMusicOnHold("Zap/3-1", "default") in new stack
     -- Executing Goto("Zap/3-1", "check_time|s|1") in new stack
     -- Goto (check_time,s,1)
     -- Executing Set("Zap/3-1", 
"FAIL_MENU=daytime|TIMEOUT_MENU=daytime") in new stack
     -- Executing GotoIfTime("Zap/3-1", 
"08:30-17:00|mon-fri|*|*|?daytime|s|1") in new stack
     -- Goto (daytime,s,1)
     -- Executing Set("Zap/3-1", "TIMEOUT(response)=1") in new stack
     -- Response timeout set to 1
     -- Executing Dial("Zap/3-1", 
"SIP/114&SIP/115&SIP/116&SIP/117|20|tr") in new stack
     -- Called 114
     -- Called 115
     -- Called 116
     -- Called 117
localhost*CLI>     -- SIP/117-0a0718d8 is ringing
localhost*CLI>     -- SIP/116-0a06c398 is ringing
localhost*CLI>     -- SIP/115-0a057678 is ringing
localhost*CLI>     -- SIP/114-0a066c58 is ringing
localhost*CLI>     -- Nobody picked up in 20000 ms
     -- Executing BackGround("Zap/3-1", "custom/no-answer") in new stack
     -- Playing 'custom/no-answer' (language 'en')
localhost*CLI>     -- Got SIP response 400 "Bad Request" back from 
192.168.1.216
localhost*CLI>     -- Timeout on Zap/3-1
   == CDR updated on Zap/3-1
     -- Executing Goto("Zap/3-1", "daytime|s|1") in new stack
     -- Goto (daytime,s,1)
     -- Executing Set("Zap/3-1", "TIMEOUT(response)=1") in new stack
     -- Response timeout set to 1
     -- Executing Dial("Zap/3-1", 
"SIP/114&SIP/115&SIP/116&SIP/117|20|tr") in new stack
     -- Called 114
     -- Called 115
     -- Called 116
     -- Called 117
localhost*CLI>     -- SIP/115-0a076e18 is ringing
localhost*CLI>     -- SIP/116-0a07c358 is ringing
localhost*CLI>     -- SIP/114-0a06c398 is ringing
localhost*CLI>     -- SIP/117-0a081898 is ringing
localhost*CLI>     -- Nobody picked up in 20000 ms
     -- Executing BackGround("Zap/3-1", "custom/no-answer") in new stack
     -- Playing 'custom/no-answer' (language 'en')
localhost*CLI>     -- Got SIP response 400 "Bad Request" back from 
192.168.1.216
localhost*CLI>     -- Timeout on Zap/3-1
   == CDR updated on Zap/3-1
     -- Executing Goto("Zap/3-1", "daytime|s|1") in new stack
     -- Goto (daytime,s,1)
     -- Executing Set("Zap/3-1", "TIMEOUT(response)=1") in new stack
     -- Response timeout set to 1
     -- Executing Dial("Zap/3-1", 
"SIP/114&SIP/115&SIP/116&SIP/117|20|tr") in new stack
     -- Called 114
     -- Called 115
     -- Called 116
     -- Called 117
localhost*CLI>     -- SIP/116-0a07c358 is ringing
localhost*CLI>     -- SIP/117-0a0718d8 is ringing
localhost*CLI>     -- SIP/115-0a057678 is ringing
localhost*CLI>     -- SIP/114-0a066c58 is ringing
localhost*CLI>   == Spawn extension (daytime, s, 2) exited non-zero on 
'Zap/3-1'
     -- Hungup 'Zap/3-1'
-- 

Warm Regards,

Lee