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

[Tony Mountifield]

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.

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. 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!

Any more hints from anyone on tracking it down would be much appreciated!

Cheers
Tony
-- 
Tony Mountifield
Work: tony at softins.co.uk - http://www.softins.co.uk
Play: tony at mountifield.org - http://tony.mountifield.org