[asterisk-users] Zap channels: no sound with certain call paths

[Tzafrir Cohen]

On Wed, Sep 12, 2007 at 09:08:23PM -0400, Christian Weeks wrote:
> Hi,
> A most peculiar and vexing problem for you all. I hope I have been
> verbose enough without being a firehose ;)
> 
> The set up:
> I have a channel bank, using the r1t1 rhino driver with a rhino T1 card
> (the channel bank itself is a very legacy piece of equipment)- this
> supplies FXS for all the house phones. Also, a Wildcard TDM400P, using
> the wctdm module with 1 FXO module, this supplies FXO to the upstream
> telco (a single line).
> 
> The problem:
> Lately, and without any configuration changes, incoming calls that route
> through the Wildcard (from the telco) to the channel bank (well, a phone
> connected to the channel bank) have no voice in either direction.
> Obviously, this is rather frustrating. The same configuration has worked
> quite reliably for the past year or so, so I am reasonably confident
> that the problem isn't directly configuration related (though I have,
> since this started occuring tried various configs).
> 
> The version where this started to occur (intermittently) was
> asterisk/zaptel in debian etch (the 1.2 branch). I have since upgraded
> to zaptel/asterisk from debian sid (the 1.4 branch) and the problems
> have gotten marginally worse.
> 
> Stuff I have tried:
> 1. Zap->Zap (calling one channel bank extn from another) works fine.
> 2. Zap->anywhere (calling out from CB to telco through wildcard, or to
> SIP provider, or IAX provider) works fine.
> 3. telco->Zap (calling in from telco to CB line) fails: no voice.
> 4. SIP/IAX->Zap (calling in from a SIP client to CB line) works.
> 
> Diagnostics examined:
> 1. ztmonitor <any line> -v shows expected signals, from the asterisk
> perspective. But e.g. in scenario 3 above, there is no received voice
> from the zap line. Which is consistent with the dialled CB line not
> being properly connected somehow.
> 
> Oddities noticed:
> 1. Sometimes, when picking up a CB line, there is no dialtone. Only
> resolution has been to reset the computer.
> 2. There are several odd messages in the log files:
> (/var/log/syslog)
> [..snip..]
> Sep 12 17:52:04 phone kernel: Got pulse digit 36 on R1T1/0/3??
> (note: lots of these, at least one per CB line, whenever we restart or
> reprobe the module)

This means many close on-hook/of-hook events. Close enough to create 36
pulse dials. This is from zaptel.ko .

> [..snip..]
> Sep 12 17:53:29 phone asterisk[2638]: rc_avpair_new: unknown attribute
> 1490026597
> (lots of these too, there seems to be a correlation between these
> messages and no voice routings)
> (/var/log/asterisk/messages (I have verbosity up nice and high))

Make sure you have debug enabled and logged if you have strange things
in chan_zap and want to full understand them.

What version of Asterisk is it?

> [Sep 12 20:35:20] WARNING[3174] chan_zap.c: Ring/Off-hook in strange
> state 6 on channel 25
> (I've had this since I set the environment up. No one seems to be able
> to give a sane answer as to why).
> 
> Finally, here's an interesting oddity. I can get the voice to come up,
> in certain circumstances, by doing the following:
> 1. Dial in from telco using cellphone.
> 2. Answer with CB Zap line. No voice.
> 3. Hang up the CB Zap line.
> 4. Re-open any Zap CB line, execute a dial that uses telco line.
> 5. The telco line picks up (to execute the dial); voice is now connected
> to the still waiting original call.
> 
> Here's the log file:
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Starting simple switch
> on 'Zap/25-1'
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Executing
> [s at telco-in:1] Goto("Zap/25-1", "incoming-home|s|1") in new stack
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Goto
> (incoming-home,s,1)
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Executing
> [s at incoming-home:1] NoOp("Zap/25-1", """ <Number>") in new stack
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Executing
> [s at incoming-home:2] Set("Zap/25-1", "TRANSFER_CONTEXT=transfer") in new
> stack
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Executing
> [s at incoming-home:3] GotoIfTime("Zap/25-1", "9:00-20:00|*|*|*?s-DAY|1")
> in new stack
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Goto
> (incoming-home,s-DAY,1)
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Executing
> [s-DAY at incoming-home:1] Dial("Zap/25-1",
> "Zap/1&Zap/3&Zap/2&Zap/10&Zap/5&Zap/6&SIP/cpw...)
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 1
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 3
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 2
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 10
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 5
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called 6
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Called <me>
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/1-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/3-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/2-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/10-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/5-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- Zap/6-1 is ringing
> [Sep 12 18:23:51] VERBOSE[3051] logger.c:     -- SIP/<me>-081f3db0 is
> ringing
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Zap/10-1 answered
> Zap/25-1
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Hungup 'Zap/6-1'
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Hungup 'Zap/5-1'
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Hungup 'Zap/2-1'
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Hungup 'Zap/3-1'
> [Sep 12 18:23:53] VERBOSE[3051] logger.c:     -- Hungup 'Zap/1-1'
> [Sep 12 18:24:04] VERBOSE[3051] logger.c:     -- Hungup 'Zap/10-1'
> [Sep 12 18:24:04] VERBOSE[3051] logger.c:   == Spawn extension
> (incoming-home, s-DAY, 1) exited non-zero on 'Zap/25-1'
> [Sep 12 18:24:04] VERBOSE[3051] logger.c:     -- Hungup 'Zap/25-1'
> [Sep 12 18:24:08] VERBOSE[3069] logger.c:     -- Starting simple switch
> on 'Zap/10-1'
> [Sep 12 18:24:16] VERBOSE[3069] logger.c:     -- Executing
> [<number>@internal:1] Dial("Zap/10-1", "Zap/25/<number>") in new stack
> [Sep 12 18:24:16] VERBOSE[3069] logger.c:     -- Called 25/<number>
> [Sep 12 18:24:20] VERBOSE[3069] logger.c:     -- Zap/25-1 answered
> Zap/10-1
> [Sep 12 18:24:20] VERBOSE[3069] logger.c:     -- Native bridging
> Zap/10-1 and Zap/25-1
> [Sep 12 18:26:25] VERBOSE[3069] logger.c:     -- Hungup 'Zap/25-1'
> [Sep 12 18:26:25] VERBOSE[3069] logger.c:   == Spawn extension
> (internal, <number>, 1) exited non-zero on 'Zap/10-1'
> [Sep 12 18:26:25] VERBOSE[3069] logger.c:     -- Hungup 'Zap/10-1'
> 
> 
> Note, throughout the above, that Zap/25 never actually hung up on me (on
> my cellphone), and the call continued when the Native bridge occurred,
> and voice was passed.
> 
> Can anyone suggest anything that might be able to help me here? This is
> very frustrating. I have a suspicion that my super-cheap eBay special
> channel bank is probably the ultimate culprit, but without hard core
> testing equipment I don't know how to verify this (and the diagnostic
> tooling available on the channel bank is, well, non-existent). I would
> like to hear others' suggestions and thoughts, as I an highly confused
> by this exceedingly peculiar problem, before I go ahead and buy another
> eBay special.

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