[asterisk-dev] Re: Weird errors returned to chan_zap by zaptel

[Tzafrir Cohen]

On Thu, Nov 09, 2006 at 12:10:05PM +0000, Tony Mountifield wrote:
> In article <20061109075731.GU14186 at xorcom.com>,
> Tzafrir Cohen <tzafrir.cohen at xorcom.com> wrote:
> > Quite a -users answer. Not sure if the is a -users question or not.
> 
> I don't think so - I'm certain it's not a configuration issue, but
> rather something in the code.
> 
> > On Wed, Nov 08, 2006 at 10:48:15PM +0000, Tony Mountifield wrote:
> > > I'm seeing some weird behaviour occurring randomly in chan_zap, and I am
> > > wondering if anyone else has ever seen anything like it, because it does
> > > not appear to make sense.
> > > 
> > > I'm posting it here initially instead of to Mantis, because I want to
> > > get some ideas on why it could be occurring, so I can fix it quickly...
> > > 
> > > I'm using Asterisk 1.2-SVN and Zaptel 1.2-SVN with a TE410P card. Operation
> > > is mostly OK, but I occasionally get the following batch of errors:
> > 
> > Have you run ztcfg (sucecessfully)? What does your zaptel.conf look
> > like? What do you see on 'zap show channels' in asterisk?
> 
> ztcfg is always run successfully as part of system startup. As I said,
> this isn't a fundamental problem. Ths system mostly works ok, receiving
> and sending calls. The problem at hand only happens occasionally.
> 
> > In addition, compare that to what you have under /proc/zaptel/ . Another
> > place to get a sort of picture of the availble channels is
> > /sys/class/zaptel/ and (if udev is used and well-configured) the 
> > projected /dev/zap/* .
> 
> Thanks, looking at /proc/zaptel/1 was the most productive. It showed all
> the channels as being (In use) except channel 2, on which the problems
> had been seen. This suggests that fd 14, which had originally been opened
> on channel 2, had indeed been closed by something, outside of chan_zap.

Must it be explicitly closed?

> 
> This was confirmed by looking at what has been logged since my last posting:
> 
> Nov  9 14:29:50 NOTICE[2844] chan_zap.c:928 zt_open: Opened '/dev/zap/pseudo', fd=14
> Nov  9 14:29:50 NOTICE[2844] chan_zap.c:928 zt_open: Opened '/dev/zap/pseudo', fd=141
> 
> I can see that one attempt to open /dev/zap/pseudo (for Meetme) was given 14
> as the file descriptor. This confirms that it had sometime been wrongly closed.
> 
> So the problem boils down to something outside of chan_zap erroneously closing
> a channel fd that it shouldn't. At least that makes sense of the error messages:
> "Bad file descriptor" when the fd was still closed, and "Inappropriate ioctl for
> device" when it had been re-opened on something entirely different.
> 
> So I need to trap all closes in asterisk and find where they are coming from. Fun!
> 
> I could do "#define close(fd) __myclose(fd)" and then somehow in __myclose()
> check the fd, perhaps against a list of channel fds that were opened for the
> PRI (and should never be closed), or perhaps there is some kind of system
> call to determine the device the fd points to.
> 
> Is it possible from within a function to get a backtrace of where it was
> called from? I would do this if I determined I was closing an unexpected fd.
> Or perhaps I just do a crash and use gdb on the core dump. 

gdb -p ?

> Unfortunately,
> people are trying to use this system in beta testing (and I need them to,
> to provoke the error), and they are 8 hours ahead of me in timezone!

I don't think that there are too many close()-s in chan_zap. Add a
comment near each. Probably faster.

One other thing: there are far too many places where chan_zap reads (or
uses an ioctl) and does not check for an error.

-- 
               Tzafrir Cohen       
icq#16849755                    jabber:tzafrir at jabber.org
+972-50-7952406           mailto:tzafrir.cohen at xorcom.com       
http://www.xorcom.com  iax:guest at local.xorcom.com/tzafrir