Problem Dialing out with and TDM400P

Hi, some 13 years ago I use to develop IVR systems based on Dialogic cards. Now after many years away from CTI, I’m taking my first steps with Asterisk. As I expected many concepts remain very similar, but getting a hold of Asterisk is probing to challenging.

[PROBLEM] Can’t dial out from a SIP phone through a POTS.

Setup: Suse 10.1 + Asterisk 1.2.10 + Zaptel 1.2.7 + Digium TDM400P with 4 FXO (only channel 1 is connected to a POTS). Relevant debug output and configuration files are at the end of the post.

First of all, dialing in to the TDM400P works fine, except for hangup detection which seems to be related to reverse polarity issues (I’ll left that for later). So I know that the card is working and the POTS are working.

The problem arises when a SIP phone sitting in the LAN tries to dial an external phone using the TDM400P to make the outbound call. The result is that Asterisk tries to dial the number on the Zap channel, thinks it’s already been answer and bridges the call back to the SIP phone. However the call is never made.

Things I’ve already checked: HW compatibility, IRQ sharing, putting ww in the Dial string. I’ve also hook an standardphone to the same POTS for monitoring the call progress when Asterisk attempts to dial, and actually what happens is that the line never goes off-hook (if I pickup the standard phone right after Asterisk says it has completed the dial, I get a dialtone)

I have the feeling I’m missing something quite obvious, but I’ve been struggling with this issue for quite a while, so I won’t hurt asking. So any help will be appreciated. Thanks in advance.


/var/log/asterisk/debug

Aug 3 02:31:43 DEBUG[19467] devicestate.c: Changing state for SIP/prueba1 - state 2 (In use)
Aug 3 02:31:43 DEBUG[19489] pbx.c: Launching 'Dial’
Aug 3 02:31:43 DEBUG[19489] chan_zap.c: Using channel 1
Aug 3 02:31:43 DEBUG[19489] channel.c: Not copying variable STACK-from-sip-95551234-1.
Aug 3 02:31:43 DEBUG[19489] channel.c: Not copying variable SIPCALLID.
Aug 3 02:31:43 DEBUG[19489] channel.c: Not copying variable SIPUSERAGENT.
Aug 3 02:31:43 DEBUG[19489] channel.c: Not copying variable SIPDOMAIN.
Aug 3 02:31:43 DEBUG[19489] channel.c: Not copying variable SIPURI.
Aug 3 02:31:43 DEBUG[19489] chan_zap.c: Dialing 'w5551234’
Aug 3 02:31:43 DEBUG[19489] chan_zap.c: Deferring dialing…

Aug 3 02:31:43 DEBUG[19489] channel.c: Set channel Zap/1-1 to read format ulaw
Aug 3 02:31:43 DEBUG[19489] channel.c: Set channel SIP/prueba1-081964e8 to write format ulaw
Aug 3 02:31:43 DEBUG[19489] channel.c: Set channel SIP/prueba1-081964e8 to read format ulaw
Aug 3 02:31:43 DEBUG[19489] channel.c: Set channel Zap/1-1 to write format ulaw
Aug 3 02:31:43 DEBUG[19467] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Aug 3 02:31:43 DEBUG[19467] devicestate.c: Changing state for Zap/1 - state 2 (In use)
Aug 3 02:31:43 DEBUG[19490] app_queue.c: Device ‘SIP/prueba1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 02:31:43 DEBUG[19491] app_queue.c: Device ‘Zap/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 02:31:43 DEBUG[19492] app_queue.c: Device ‘Zap/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 02:31:44 DEBUG[19489] chan_zap.c: Exception on 14, channel 1
Aug 3 02:31:44 DEBUG[19489] chan_zap.c: Got event Hook Transition Complete(12) on channel 1 (index 0)
Aug 3 02:31:46 DEBUG[19489] chan_zap.c: Exception on 14, channel 1
Aug 3 02:31:46 DEBUG[19489] chan_zap.c: Got event Dial Complete(9) on channel 1 (index 0)
Aug 3 02:31:46 DEBUG[19489] chan_zap.c: Enabled echo cancellation on channel 1
Aug 3 02:31:46 DEBUG[19489] channel.c: Set channel SIP/prueba1-081964e8 to read format ulaw
Aug 3 02:31:46 DEBUG[19489] channel.c: Set channel Zap/1-1 to write format ulaw
Aug 3 02:31:46 DEBUG[19489] channel.c: Set channel Zap/1-1 to read format ulaw
Aug 3 02:31:46 DEBUG[19489] channel.c: Set channel SIP/prueba1-081964e8 to write format ulaw
Aug 3 02:31:46 DEBUG[19489] chan_sip.c: sip_answer(SIP/prueba1-081964e8)

/etc/zaptel.conf

fxsls=1
loadzone=es
defaultzone=es

/etc/asterisk/zapata.conf

[channels]
echocancel=yes
signalling=fxs_ls
context=inbound
busydetect=no
callprogress=no
faxdetect=no
immediate=no
channel => 1

/etc/asterisk/extensions.conf

[from-sip]
ignorepat => 9
exten => 6001,1,Dial(SIP/prueba1)

exten => _9.,1,Dial(Zap/1/w${EXTEN:1},20)
exten => _9.,2,Congestion()
exten => _9.,102,Congestion()

I’m no expert here, but is the complete number being dialled? Ignorepat says to ignore the 9, ok, but then you ask for a substring of the exten beginning at position 1, which if the string is zero based will be second digit in. If this is so then the number will be a digit short?

As far as I know:

ignorepat has no effect over the dial string, it’s function being to instruct Asterisk to maintain the dialtone after the 9 digit has been pressed. This is done to simulate the dialtone from the outside line, because usually this is what happends when you dial 9 in a traditional PBX setup.

And the argument in ${EXTEN:1} represents the number of digits to strip from the beginning of the extension, so this only removes the 9, which is used to indicate that the user is trying to reach and outside number.

This can be verified looking at the debug output, where the number that Asterisk is trying to dial is correct, no digits missing. Also several of the examples provided by default with Asterisk use the same ${EXTEN:n} to remove the first n digits as needed by the application.

Thanks for the reply.

Add some waits before dialing the number in the dialplan

ex.
exten => _9X.,1,Dial(Zap/g1/wwww${EXTEN:1})

I’ve already triedwith several www before de ${EXTEN:1} and the result is the same.

I looks to me, as if for some reason Asterisk is not getting the line to go off-hook before starting to dial.

I don’t know if this is of any help, but I have a similar setup and this is my debug output when I call from an xlite sip phone successfully through an asterisk box to an outside phone number (snipped to show the same general area of concern) Suse 9.0, * 1.2.10, zaptel 1.2.6


Aug 3 19:22:51 DEBUG[5525] chan_sip.c: Checking SIP call limits for device 21
Aug 3 19:22:51 DEBUG[5525] chan_sip.c: Updating call counter for incoming call
Aug 3 19:22:51 DEBUG[5525] chan_sip.c: build_route: Contact hop: sip:21@192.168.0.23:39002
Aug 3 19:22:51 DEBUG[5555] pbx.c: Launching 'Dial’
Aug 3 19:22:51 DEBUG[5555] chan_zap.c: Using channel 4
Aug 3 19:22:51 DEBUG[5555] channel.c: Not copying variable STACK-default-6135458550-1.
Aug 3 19:22:51 DEBUG[5555] channel.c: Not copying variable SIPCALLID.
Aug 3 19:22:51 DEBUG[5555] channel.c: Not copying variable SIPUSERAGENT.
Aug 3 19:22:51 DEBUG[5555] channel.c: Not copying variable SIPDOMAIN.
Aug 3 19:22:51 DEBUG[5555] channel.c: Not copying variable SIPURI.
Aug 3 19:22:51 DEBUG[5555] chan_zap.c: Dialing '6135458550’
Aug 3 19:22:51 DEBUG[5555] chan_zap.c: Deferring dialing…
Aug 3 19:22:51 DEBUG[5509] chan_sip.c: Checking device state for peer 21
Aug 3 19:22:51 DEBUG[5509] devicestate.c: Changing state for SIP/21 - state 2 (In use)
Aug 3 19:22:51 DEBUG[5556] app_queue.c: Device ‘SIP/21’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 19:22:51 DEBUG[5509] devicestate.c: Changing state for Zap/4 - state 2 (In use)
Aug 3 19:22:51 DEBUG[5557] app_queue.c: Device ‘Zap/4’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 19:22:51 DEBUG[5509] devicestate.c: Changing state for Zap/4 - state 2 (In use)
Aug 3 19:22:51 DEBUG[5558] app_queue.c: Device ‘Zap/4’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
Aug 3 19:22:51 DEBUG[5555] channel.c: Set channel Zap/4-1 to read format slin
Aug 3 19:22:51 DEBUG[5555] channel.c: Set channel SIP/21-081a0ef0 to write format slin
Aug 3 19:22:51 DEBUG[5555] channel.c: Set channel SIP/21-081a0ef0 to read format slin
Aug 3 19:22:51 DEBUG[5555] channel.c: Set channel Zap/4-1 to write format slin
Aug 3 19:22:52 DEBUG[5555] chan_zap.c: Exception on 14, channel 4
Aug 3 19:22:52 DEBUG[5555] chan_zap.c: Got event Hook Transition Complete(12) on channel 4 (index 0)
Aug 3 19:22:59 DEBUG[5525] chan_sip.c: Auto destroying call 'd344b65efc3d6d7dYTY0NjBkZWFmMWVkNzMxZTAzODk1NTZkN2NhOWU2NjI.'
Aug 3 19:23:04 DEBUG[5555] chan_zap.c: Exception on 14, channel 4
Aug 3 19:23:04 DEBUG[5555] chan_zap.c: Got event Dial Complete(9) on channel 4 (index 0)
Aug 3 19:23:04 DEBUG[5555] chan_zap.c: Enabled echo cancellation on channel 4
Aug 3 19:23:04 DEBUG[5555] channel.c: Set channel SIP/21-081a0ef0 to read format slin
Aug 3 19:23:04 DEBUG[5555] channel.c: Set channel Zap/4-1 to write format slin
Aug 3 19:23:04 DEBUG[5555] channel.c: Set channel Zap/4-1 to read format slin
Aug 3 19:23:04 DEBUG[5555] channel.c: Set channel SIP/21-081a0ef0 to write format slin
Aug 3 19:23:04 DEBUG[5555] chan_sip.c: sip_answer(SIP/21-081a0ef0)

i add w four times and it fixed for me…
asterisk 1.4.11 and zaptel 1.4.6