[Home]

Summary:ASTERISK-03486: dial_exec_full errors
Reporter:denon (denon)Labels:
Date Opened:2005-02-11 10:13:47.000-0600Date Closed:2011-06-07 14:04:40
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:We've been having problems with getting the below errors. I've tried several different builds over the past week or so, and had issues with all of them, including what I'm currently running (CVS-HEAD-02/10/05-12:17:52). I've been getting this error on ZAP and IAX2 trunks.  After a restart, things will run fine for a couple or few hours, then all calls will stop, and I'll find these on the console:

   -- Executing Dial("SIP/cisco32-b3da", "Zap/19/18005551212") in new stack
Dec 13 14:49:49 NOTICE[17082]: app_dial.c:927 dial_exec_full: Unable to create channel of type 'Zap' (cause 0)
 == Everyone is busy/congested at this time (1:0/0/1)

Most likely unrelated, but DTMF from Cisco 7960s will also frequently stop working after this has occured (and often even persist after a restart).
Comments:By: denon (denon) 2005-02-11 15:09:12.000-0600

When it happens, show channels doesn't show anything in use.

Here's one of the pstn trunks it tried to use:
pbx*CLI> zap show channel 17
Channel: 17
File Descriptor: 17
Span: 1
Extension:
Dialing: no
Context: pstn1
Caller ID:
Calling TON: 0
Caller ID name:
Destroy: 0
InAlarm: 0
Signalling Type: FXS Kewlstart
Owner: <None>
Real: <None>
Callwait: <None>
Threeway: <None>
Confno: -1
Propagated Conference: -1
Real in conference: 0
DSP: no
Relax DTMF: no
Dialing/CallwaitCAS: 0/0
Default law: ulaw
Fax Handled: no
Pulse phone: no
Echo Cancellation: 128 taps, currently OFF
Actual Confinfo: Num/0, Mode/0x0000
Actual Confmute: No
Hookstate (FXS only): Onhook
-----
Here's an FXS port, for reference:
Channel: 6
File Descriptor: 30
Span: 1
Extension:
Dialing: no
Context: internal
Caller ID: 12
Calling TON: 0
Caller ID name: Warehouse Desk
Destroy: 0
InAlarm: 0
Signalling Type: FXO Kewlstart
Owner: <None>
Real: <None>
Callwait: <None>
Threeway: <None>
Confno: -1
Propagated Conference: -1
Real in conference: 0
DSP: no
Relax DTMF: no
Dialing/CallwaitCAS: 0/0
Default law: ulaw
Fax Handled: no
Pulse phone: no
Echo Cancellation: 128 taps, currently OFF
Actual Confinfo: Num/0, Mode/0x0000
Actual Confmute: No
ookstate (FXS only): Onhook

SIP to SIP works during this time.

SIP to IAX2 does not:
Dec 13 14:51:38 WARNING[20990]: chan_iax2.c:913 find_callno: No more space
Dec 13 14:51:38 WARNING[20990]: chan_iax2.c:6966 iax2_request: Unable to create call
Dec 13 14:51:38 NOTICE[20990]: app_dial.c:927 dial_exec_full: Unable to create channel of type 'IAX2' (cause 34)

Plain inbound IAX2 (nufone trunk) into IVR also does not work.
By: Mark Spencer (markster) 2005-02-11 16:29:25.000-0600

find_callno saying no more space means there are the maximum number of active calls.  This seems a bit unlikely.  Have you tried rm -rf /usr/lib/asterisk/modules and then make clean ; make install?
By: Clod Patry (junky) 2005-02-11 18:24:44.000-0600

in your dial, you're making a call to zap/19, and in your last note, you're doing a zap show channel 17. Is Zap/19 is the same of Zap/17?

I'm getting that kind of errors, when my remote end has locked up this channel. Could that possible ? I guess no, cause you're dialing from that Zap directly to PSTN right?

Does Zap/19 is part of a group? Have you the same behavior when dialing a group too?

How many channels are like that one?
By: denon (denon) 2005-02-11 18:38:23.000-0600

I've rebuilt after clearing the modules out - we'll see what happens. I'll keep an eye on it over the weekend, hopefully if it's going to break, it'll break even without much call volume.

All zap and sip channels act the same when it blows up.  17,18,19,etc are all in the outbound channels. It was trying to dial out of them specifically, not a group, using +101s. It also attempts a SIP further down, using +101 - same result. None of the lines are in use when this happens, and it's immediately resolved when I do a "restart now".
By: Clod Patry (junky) 2005-02-11 21:02:46.000-0600

im setting the severity to major since denon can't make any outbound calls.
By: denon (denon) 2005-02-11 21:13:15.000-0600

On irc, Junky requested the following info:

The "zap show channels" of a few channels while it's happening: http://pastebin.com/240795

Also, the console output as it tries several channels for outbound, zap and sip:
   -- Executing SetVar("SIP/cisco32-5240", "CALLFILENAME=19011213-145326--2147483195.39-918005551212-s") in new stack
   -- Executing Monitor("SIP/cisco32-5240", "wav|19011213-145326--2147483195.39-918005551212-s") in new stack
   -- Executing Dial("SIP/cisco32-5240", "Zap/18/18005551212") in new stack
Dec 13 14:53:26 NOTICE[7079]: app_dial.c:927 dial_exec_full: Unable to create channel of type 'Zap' (cause 0)
 == Everyone is busy/congested at this time (1:0/0/1)
   -- Executing Dial("SIP/cisco32-5240", "Zap/17/18005551212") in new stack
Dec 13 14:53:26 NOTICE[7079]: app_dial.c:927 dial_exec_full: Unable to create channel of type 'Zap' (cause 0)
 == Everyone is busy/congested at this time (1:0/0/1)
   -- Executing Dial("SIP/cisco32-5240", "Zap/19/18005551212") in new stack
Dec 13 14:53:26 NOTICE[7079]: app_dial.c:927 dial_exec_full: Unable to create channel of type 'Zap' (cause 0)
 == Everyone is busy/congested at this time (1:0/0/1)
   -- Executing Dial("SIP/cisco32-5240", "SIP/sipura1pstn1/*6718005551212") in new stack
   -- Called sipura1pstn1/*6718005551212
   -- Got SIP response 503 "Service Unavailable" back from 206.8.93.30
   -- SIP/sipura1pstn1-3616 is circuit-busy
 == Everyone is busy/congested at this time (1:0/1/0)
By: denon (denon) 2005-02-12 20:56:45.000-0600

I've been doing some more digging - I'm not sure that I've necessarily found the problem, but I'm very hopeful.

It seems the box was syncing with a very unreliable ntp source. So, for some reason, the client was occasionally setting the clock to the year 1901. Asterisk, of course, freaked out when the clock jumped back. However, restarting Asterisk, and having it start up in the year 1901, seemed to operate normal.  This would be a negative unixtime, right? (as 1901 < 1/1/1970). I assume that'd cause problems? Obviously, if this is the problem, it's certainly something that shouldn't have happened. However, if it really is the problem, maybe a small conditional should be popped in where the code is actually breaking, checking for a negative or whatever the problem actually is. If anything, just throwing something to the console about an invalid clock drift or the like.

I'll keep you posted on what we see.
By: nick (nick) 2005-02-12 23:26:38.000-0600

time_t is signed, so negitave years since the epoch can be used. The earliest year that can be represented with 32-bit Unix time is Friday December 13 20:45:52 UTC 1901, which is why your system is reverting to that date.

Nick
By: Mark Spencer (markster) 2005-02-13 01:00:39.000-0600

Going backwards in time can definitely screw things up.
By: Clod Patry (junky) 2005-02-13 21:37:13.000-0600

And if the time is set correctly is there any more troubles?

Btw denon, what date and time was set (of the year 1901)?

for SNTP servers, you can use time.apple.com, which works fine for my IP500s.