[Asterisk-Users] TDM400 won't answer or dial. Help?
Stewart Loving-Gibbard
sloving-gibbard at uswest.net
Tue Jul 4 22:16:53 MST 2006
I've spent several days now trying to get my TDM400 card to work. I'm
running TrixBox 1.1 (at least to start). I've tried an old PII 233mhz
with 256 MB, and a modern Dell Dimension 8400 (P4 3.0 ghz, 1 GM RAM). On
both machines I have a series of installation headaches, some of which
seem to be TrixBox's fault, since they are fairly consistent between
machines.
I can get Asterix & FreePBX working as long as I don't use the TDM400.
It seems to work great with the soft SIP phone. I can dial into it, get
voicemail, record messages, etc. But I need it to work with the TDM400
card to be useful. I've followed the Nerd Vittles and SureTeq guides
approximately, and think I should have the ability to receive calls and
dial out over the TDM's FXO port.
When I dial in, and watch from FreePBX's panel, I see that the "Zap 1"
trunk goes red. The SIP soft phone I have the call directed to then gets
the call. I have the SIP soft phone on auto-answer, so it picks up. Or,
rather, it thinks it picks up, since the calling phone continues to ring
and eventually goes to my POTS voicemail.
A similar thing happens when I dial out. I call my cell phone, Zap 1
trunk goes red again, and the soft SIP phone says "call established" but
the call never gets made on the phone line. (I can pick up with a
conventional phone and get a dialtone.)
It seems to me that * has recognized the TDM correctly, and that I've
picked the right port on my TDM. But, something is clearly wrong, and I
can't find mention of this kind of thing in the FAQs.
-------------
Here I call the inbound trunk, which Asterisk is supposed to pick up.
[root at asterisk1 etc]# asterisk -rvvvv
== Parsing '/etc/asterisk/asterisk.conf': Found
== Parsing '/etc/asterisk/extconfig.conf': Found
Asterisk 1.2.9.1 svn rev 34876, Copyright (C) 1999 - 2006 Digium, Inc.
and others.
Created by Mark Spencer <markster at digium.com>
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for
details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it
under
certain conditions. Type 'show license' for details.
=========================================================================
Connected to Asterisk 1.2.9.1 svn rev 34876 currently running on
asterisk1 (pid = 3170)
Verbosity was 1 and is now 4
Core debug is at least 1
-- Starting simple switch on 'Zap/1-1'
-- Executing NoOp("Zap/1-1", "Entering from-zaptel with DID == ")
in new stack
-- Executing Set("Zap/1-1", "DID=s") in new stack
-- Executing NoOp("Zap/1-1", "DID is now s") in new stack
-- Executing GotoIf("Zap/1-1", "1?zapok:notzap") in new stack
-- Goto (from-zaptel,s,7)
-- Executing NoOp("Zap/1-1", "Is a Zaptel Channel") in new stack
-- Executing Set("Zap/1-1", "CHAN=1-1") in new stack
-- Executing Set("Zap/1-1", "CHAN=1") in new stack
-- Executing Macro("Zap/1-1", "from-zaptel-1|s|1") in new stack
-- Executing NoOp("Zap/1-1", "Returned from Macro from-zaptel-1")
in new stack
-- Executing Goto("Zap/1-1", "ext-did|s|1") in new stack
-- Goto (ext-did,s,1)
-- Executing Set("Zap/1-1", "FROM_DID=s") in new stack
-- Executing Set("Zap/1-1", "FAX_RX=disabled") in new stack
-- Executing Goto("Zap/1-1", "ext-local|200|1") in new stack
-- Goto (ext-local,200,1)
-- Executing Macro("Zap/1-1", "exten-vm|200|200") in new stack
-- Executing Macro("Zap/1-1", "user-callerid") in new stack
-- Executing GotoIf("Zap/1-1", "0?report") in new stack
-- Executing GotoIf("Zap/1-1", "0?start") in new stack
-- Executing Set("Zap/1-1", "REALCALLERIDNUM=") in new stack
-- Executing NoOp("Zap/1-1", "REALCALLERIDNUM is ") in new stack
-- Executing Set("Zap/1-1", "AMPUSER=") in new stack
-- Executing Set("Zap/1-1", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("Zap/1-1", "1?report") in new stack
-- Goto (macro-user-callerid,s,9)
-- Executing NoOp("Zap/1-1", "Using CallerID "" <>") in new stack
-- Executing Set("Zap/1-1", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("Zap/1-1", "VMBOX=200") in new stack
-- Executing Set("Zap/1-1", "EXTTOCALL=200") in new stack
-- Executing Set("Zap/1-1", "CFUEXT=") in new stack
-- Executing Set("Zap/1-1", "RT=15") in new stack
-- Executing Macro("Zap/1-1", "record-enable|200|IN") in new stack
-- Executing GotoIf("Zap/1-1", "0 > 0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("Zap/1-1",
"recordingcheck|20060704-220403|1152075839.2") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20060704-220403|1152075839.2: Inbound recording enabled.
recordingcheck|20060704-220403|1152075839.2:
CALLFILENAME=20060704-220403-1152075839.2
-- AGI Script recordingcheck completed, returning 0
-- Executing Monitor("Zap/1-1",
"wav49|20060704-220403-1152075839.2| mb") in new stack
-- Executing GotoIf("Zap/1-1", "0?dolocaldial|1") in new stack
-- Executing Macro("Zap/1-1", "dial|15|tr|200") in new stack
-- Executing AGI("Zap/1-1", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
-- dialparties.agi: priority is 1
dialparties.agi: Caller ID name is 'unknown' number is 'unknown'
dialparties.agi: Methodology of ring is 'none'
-- dialparties.agi: Added extension 200 to extension map
-- dialparties.agi: Extension 200 cf is disabled
-- dialparties.agi: Extension 200 do not disturb is disabled
> dialparties.agi: extnum: 200
> dialparties.agi: exthascw: 0
> dialparties.agi: exthascfb: 0
> dialparties.agi: extcfb:
> dialparties.agi: exthascfu: 0
> dialparties.agi: extcfu:
== Manager 'admin' logged on from 127.0.0.1
== Manager 'admin' logged off from 127.0.0.1
> dialparties.agi: ExtensionState: 0
-- dialparties.agi: Checking CW and CFB status for extension 200
-- dialparties.agi: DbSet CALLTRACE/200 to unknown
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("Zap/1-1", "SIP/200|15|tr") in new stack
-- Called 200
-- SIP/200-423d is ringing
-- SIP/200-423d answered Zap/1-1
-- ***[JB LOG]*** fixed jitterbuffer created on channel Zap/1-1
[Supposedly Asterisk has answered here, and the call is in progress, but
in fact the TDM400 card has not picked up.]
[Here I hang up the soft phone]
-- Hungup 'Zap/1-1'
-- ***[JB LOG]*** fixed jitterbuffer destroyed on channel Zap/1-1
asterisk1*CLI>
-----------------------------------
I have just one FXO daughterboard on my TRM400 right now, nothing else.
[root at asterisk1 ~]# ztcfg -vv
Zaptel Version: SVN-trunk-r1199
Echo Canceller: MG2
Configuration
======================
Channel map:
Channel 01: FXS Kewlstart (Default) (Slaves: 01)
1 channels configured.
-----------------------------------------------------------------
Here's the same inbound call again, from /var/log/asterisk/full.
Jul 4 21:11:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:13:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:13:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:15:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:15:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:17:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:17:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:19:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:19:48 DEBUG[3403] manager.c: Manager received command 'Command'
Jul 4 21:20:14 DEBUG[3246] chan_zap.c: Monitor doohicky got event Ring
Begin on channel 1
Jul 4 21:20:16 DEBUG[3246] chan_zap.c: Monitor doohicky got event
Ring/Answered on channel 1
Jul 4 21:20:16 DEBUG[4605] app_queue.c: Device 'Zap/1' changed to state
'2' (In use) but we don't care becaus
e they're not a member of any queue.
Jul 4 21:20:16 VERBOSE[4606] logger.c: -- Starting simple switch on
'Zap/1-1'
Jul 4 21:20:24 WARNING[4606] chan_zap.c: CallerID returned with error
on channel 'Zap/1-1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"Entering from-zaptel with DID == ")
in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is 's'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"DID=s") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"DID is now s") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "1?zapok:notzap") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Goto (from-zaptel,s,7)
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"Is a Zaptel Channel") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"CHAN=1-1") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"CHAN=1") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Macro'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Macro("Zap/1-1", "from-zaptel-1|s|1") in new stack
Jul 4 21:20:24 WARNING[4606] app_macro.c: No such context
'macro-from-zaptel-1' for macro 'from-zaptel-1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"Returned from Macro from-zaptel-1")
in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Goto'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Goto("Zap/1-1",
"ext-did|s|1") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Goto (ext-did,s,1)
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"FROM_DID=s") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"FAX_RX=disabled") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Goto'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Goto("Zap/1-1",
"ext-local|200|1") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Goto (ext-local,200,1)
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Macro'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Macro("Zap/1-1", "exten-vm|200|200") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Macro'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Macro("Zap/1-1", "user-callerid") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '0'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "0?report") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Not taking any branch
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '0'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "0?start") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Not taking any branch
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is ''
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"REALCALLERIDNUM=") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"REALCALLERIDNUM is ") in new stack
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '/user' in family
'DEVICE'
Jul 4 21:20:24 DEBUG[4606] func_db.c: DB: DEVICE//user not found in
database.
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is ''
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"AMPUSER=") in new stack
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '/cidname' in
family 'AMPUSER'
Jul 4 21:20:24 DEBUG[4606] func_db.c: DB: AMPUSER//cidname not found in
database.
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is ''
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"AMPUSERCIDNAME=") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "1?report") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Goto
(macro-user-callerid,s,9)
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is '"" <>'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'NoOp'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing NoOp("Zap/1-1",
"Using CallerID "" <>") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"FROMCONTEXT=exten-vm") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"VMBOX=200") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"EXTTOCALL=200") in new stack
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'CFU'
Jul 4 21:20:24 DEBUG[4606] func_db.c: DB: CFU/200 not found in database.
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is ''
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"CFUEXT=") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '0'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '1'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is '15'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Set'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Set("Zap/1-1",
"RT=15") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Macro'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Macro("Zap/1-1", "record-enable|200|IN") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Function result is '0'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "0 > 0?2:4") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Goto
(macro-record-enable,s,4)
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'AGI'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing AGI("Zap/1-1",
"recordingcheck|20060704-212024|115207
3216.0") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/recordingcheck
Jul 4 21:20:24 VERBOSE[4606] logger.c:
recordingcheck|20060704-212024|1152073216.0: Inbound recording enabl
ed.
Jul 4 21:20:24 VERBOSE[4606] logger.c:
recordingcheck|20060704-212024|1152073216.0: CALLFILENAME=20060704-2
12024-1152073216.0
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- AGI Script recordingcheck
completed, returning 0
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Monitor'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Monitor("Zap/1-1", "wav49|20060704-212024-1152073216.
0| mb") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Expression result is '0'
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'GotoIf'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
GotoIf("Zap/1-1", "0?dolocaldial|1") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Not taking any branch
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Macro'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing
Macro("Zap/1-1", "dial|15|tr|200") in new stack
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'AGI'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing AGI("Zap/1-1",
"dialparties.agi") in new stack
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/dialparties.agi
Jul 4 21:20:24 VERBOSE[4606] logger.c: dialparties.agi: Starting New
Dialparties.agi
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi:
priority is 1
Jul 4 21:20:24 VERBOSE[4606] logger.c: dialparties.agi: Caller ID
name is 'unknown' number is 'unknown'
Jul 4 21:20:24 VERBOSE[4606] logger.c: dialparties.agi: Methodology
of ring is 'none'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi: Added
extension 200 to extension map
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'CF'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi:
Extension 200 cf is disabled
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'DND'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi:
Extension 200 do not disturb is disabled
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'CW'
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'CFB'
Jul 4 21:20:24 DEBUG[4606] db.c: Unable to find key '200' in family 'CFU'
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi:
extnum: 200
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi:
exthascw: 0
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi:
exthascfb: 0
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi: extcfb:
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi:
exthascfu: 0
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi: extcfu:
Jul 4 21:20:24 DEBUG[4609] manager.c: Manager received command 'login'
Jul 4 21:20:24 DEBUG[4609] config.c: Parsing /etc/asterisk/manager.conf
Jul 4 21:20:24 DEBUG[4609] config.c: Parsing
/etc/asterisk/manager_custom.conf
Jul 4 21:20:24 WARNING[4609] config.c: Unknown directive
'permit=192.168.1.0/255.255.255.0' at line 18 of man
ager_custom.conf
Jul 4 21:20:24 DEBUG[4609] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to
acl for peer
Jul 4 21:20:24 DEBUG[4609] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0
appended to acl for peer
Jul 4 21:20:24 DEBUG[4609] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Jul 4 21:20:24 DEBUG[4609] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Jul 4 21:20:24 VERBOSE[4609] logger.c: == Manager 'admin' logged on
from 127.0.0.1
Jul 4 21:20:24 DEBUG[4609] manager.c: Manager received command
'ExtensionState'
Jul 4 21:20:24 DEBUG[4609] manager.c: Manager received command 'Logoff'
Jul 4 21:20:24 VERBOSE[4609] logger.c: == Manager 'admin' logged off
from 127.0.0.1
Jul 4 21:20:24 VERBOSE[4606] logger.c: > dialparties.agi:
ExtensionState: 0
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi:
Checking CW and CFB status for extension 200
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- dialparties.agi: DbSet
CALLTRACE/200 to unknown
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- AGI Script
dialparties.agi completed, returning 0
Jul 4 21:20:24 DEBUG[4606] pbx.c: Launching 'Dial'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Executing Dial("Zap/1-1",
"SIP/200|15|tr") in new stack
Jul 4 21:20:24 DEBUG[4606] chan_sip.c: Allocating new SIP dialog for
(No Call-ID) - INVITE (With RTP)
Jul 4 21:20:24 DEBUG[4606] chan_sip.c: Setting NAT on RTP to 0
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-dial-s-10.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable MACRO_DEPTH.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable ds.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-dial-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable ARG3.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable ARG2.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable ARG1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable MACRO_PRIORITY.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable MACRO_CONTEXT.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable MACRO_EXTEN.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-9.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-8.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable AUTO_MONITOR.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-record-enable-s-999.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable CALLFILENAME.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-record-enable-s-4.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-record-enable-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-7.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable RT.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-6.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable CFUEXT.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-5.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable EXTTOCALL.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-4.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable VMBOX.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-3.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable FROMCONTEXT.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-2.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-9.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-7.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable AMPUSERCIDNAME.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-6.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable AMPUSER.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-5.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-4.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable REALCALLERIDNUM.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-3.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-2.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-user-callerid-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-macro-exten-vm-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-ext-local-200-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-ext-did-s-3.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable FAX_RX.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-ext-did-s-2.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable FROM_DID.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-ext-did-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-12.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-11.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-10.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable CHAN.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-9.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-8.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-7.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-4.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-3.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable DID.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-2.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
STACK-from-zaptel-s-1.
Jul 4 21:20:24 DEBUG[4606] channel.c: Not copying variable
TRANSFERCAPABILITY.
Jul 4 21:20:24 DEBUG[4606] chan_sip.c: Outgoing Call for 200
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- Called 200
Jul 4 21:20:24 DEBUG[4606] chan_zap.c: Requested indication 3 on
channel Zap/1-1
Jul 4 21:20:24 DEBUG[3248] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on '581f9
ca90b39f22302e17c031e12b67b at 10.0.0.212' Request 102: Found
Jul 4 21:20:24 DEBUG[3210] channel.c: Avoiding initial deadlock for
'SIP/200-cd7e'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- SIP/200-cd7e is ringing
Jul 4 21:20:24 DEBUG[4610] app_queue.c: Device 'SIP/200' changed to
state '6' (Ringing) but we don't care bec
ause they're not a member of any queue.
Jul 4 21:20:24 DEBUG[4606] rtp.c: Got RTCP report of 132 bytes
Jul 4 21:20:24 DEBUG[3248] chan_sip.c: Acked pending invite 102
Jul 4 21:20:24 DEBUG[3248] chan_sip.c: Stopping retransmission on
'581f9ca90b39f22302e17c031e12b67b at 10.0.0.21
2' of Request 102: Match Found
Jul 4 21:20:24 DEBUG[3248] chan_sip.c: build_route: Contact hop:
<sip:200 at 10.0.0.12:30540;rinstance=287de7801
e287bce>
Jul 4 21:20:24 DEBUG[3210] channel.c: Avoiding initial deadlock for
'SIP/200-cd7e'
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- SIP/200-cd7e answered Zap/1-1
Jul 4 21:20:24 DEBUG[4606] chan_zap.c: Requested indication -1 on
channel Zap/1-1
Jul 4 21:20:24 DEBUG[4606] channel.c: Set channel Zap/1-1 to read
format ulaw
Jul 4 21:20:24 DEBUG[4606] channel.c: Set channel SIP/200-cd7e to write
format ulaw
Jul 4 21:20:24 DEBUG[4606] channel.c: Set channel SIP/200-cd7e to read
format ulaw
Jul 4 21:20:24 DEBUG[4606] channel.c: Set channel Zap/1-1 to write
format ulaw
Jul 4 21:20:24 DEBUG[4606] chan_zap.c: Took Zap/1-1 off hook
^^^^ This is NOT happening!
Jul 4 21:20:24 DEBUG[4606] chan_zap.c: Enabled echo cancellation on
channel 1
Jul 4 21:20:24 DEBUG[4606] chan_zap.c: Engaged echo training on channel 1
Jul 4 21:20:24 DEBUG[4611] app_queue.c: Device 'SIP/200' changed to
state '2' (In use) but we don't care beca
use they're not a member of any queue.
Jul 4 21:20:24 DEBUG[4612] app_queue.c: Device 'Zap/1' changed to state
'2' (In use) but we don't care becaus
e they're not a member of any queue.
Jul 4 21:20:24 DEBUG[4606] rtp.c: Ooh, format changed from unknown to ulaw
Jul 4 21:20:24 VERBOSE[4606] logger.c: -- ***[JB LOG]*** fixed
jitterbuffer created on channel Zap/1-1
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
Jul 4 21:20:24 DEBUG[4606] channel.c: Nobody there, continuing...
[Many more of these...]
Jul 4 22:05:19 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:19 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] rtp.c: Got RTCP report of 176 bytes
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:20 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:21 DEBUG[5555] channel.c: Nobody there, continuing...
Jul 4 22:05:21 DEBUG[5555] rtp.c: Got RTCP report of 160 bytes
Jul 4 22:05:21 DEBUG[5555] channel.c: Didn't get a frame from channel:
SIP/200-423d
Jul 4 22:05:21 DEBUG[5555] channel.c: Bridge stops bridging channels
Zap/1-1 and SIP/200-423d
Jul 4 22:05:21 DEBUG[5555] channel.c: Hanging up channel 'SIP/200-423d'
Jul 4 22:05:21 DEBUG[5555] chan_sip.c: Hangup call SIP/200-423d, SIP
callid 165b198b26cbf6913e2fed721cc09a45 at 10.0.0.212)
Jul 4 22:05:21 DEBUG[5555] chan_sip.c: update_call_counter(200) -
decrement call limit counter
Jul 4 22:05:21 DEBUG[5555] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jul 4 22:05:21 DEBUG[5555] app_macro.c: Spawn extension
(macro-dial,s,10) exited non-zero on 'Zap/1-1' in macro 'dial'
Jul 4 22:05:21 DEBUG[5555] app_macro.c: Spawn extension
(macro-dial,s,10) exited non-zero on 'Zap/1-1' in macro 'exten-vm'
Jul 4 22:05:21 DEBUG[5775] app_queue.c: Device 'SIP/200' changed to
state '1' (Not in use) but we don't care because they're not a member of
any queue.
Jul 4 22:05:21 DEBUG[5555] pbx.c: Spawn extension (macro-dial,s,10)
exited non-zero on 'Zap/1-1'
Jul 4 22:05:21 DEBUG[5555] cdr_addon_mysql.c: cdr_mysql: inserting a
CDR record.
Jul 4 22:05:21 DEBUG[5555] cdr_addon_mysql.c: cdr_mysql: SQL command as
follows: INSERT INTO cdr
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid)
VALUES ('2006-07-04 22:04:03','','','200','ext-local',
'Zap/1-1','SIP/200-423d','Monitor','wav49|20060704-220403-1152075839.2|
mX',78,78,'ANSWERED',3,'','1152075839.2')
Jul 4 22:05:21 DEBUG[5555] channel.c: Hanging up channel 'Zap/1-1'
Jul 4 22:05:21 DEBUG[5555] chan_zap.c: zt_hangup(Zap/1-1)
Jul 4 22:05:21 DEBUG[5555] chan_zap.c: Hangup: channel: 1 index = 0,
normal = 13, callwait = -1, thirdcall = -1
Jul 4 22:05:21 DEBUG[5555] chan_zap.c: disabled echo cancellation on
channel 1
Jul 4 22:05:21 DEBUG[5555] chan_zap.c: Set option TDD MODE, value:
OFF(0) on Zap/1-1
Jul 4 22:05:21 DEBUG[5555] chan_zap.c: Updated conferencing on 1, with
0 conference users
Jul 4 22:05:21 VERBOSE[5555] logger.c: -- Hungup 'Zap/1-1'
Jul 4 22:05:21 DEBUG[5555] res_monitor.c: monitor executing ( nice -n
19 soxmix
"/var/spool/asterisk/monitor/20060704-220403-1152075839.2-in.WAV"
"/var/spool/asterisk/monitor/20060704-220403-1152075839.2-out.WAV"
"/var/spool/asterisk/monitor/20060704-220403-1152075839.2.WAV" && rm -f
"/var/spool/asterisk/monitor/20060704-220403-1152075839.2-"* ) &
Jul 4 22:05:21 VERBOSE[5555] logger.c: -- ***[JB LOG]*** fixed
jitterbuffer destroyed on channel Zap/1-1
Jul 4 22:05:21 DEBUG[5779] app_queue.c: Device 'Zap/1' changed to state
'0' (Unknown) but we don't care because they're not a member of any queue.
Jul 4 22:07:08 DEBUG[3543] manager.c: Manager received command 'Command'
Jul 4 22:07:08 DEBUG[3543] manager.c: Manager received command 'Command'
[root at asterisk1 asterisk]#
------------------------------------------------------------------------
Help? Is there anything else I can do?
Stew
More information about the asterisk-users
mailing list