Douglas Mortensen
2010-Jun-21 17:39 UTC
[asterisk-users] How to tell if a dropped call is my fault
I just had a user report that they called out to someone on a cell phone this
morning, and after a short conversation, the call was dropped/lost. The person
on the cell phone says that this is very rare, and would not suspect the
dropped/lost call to be on their side. I have looked at the asterisk/full log as
thoroughly as I can, and have pasted the lines which seem relevant to that call
below. From what I can tell, only the last 26 lines of the log really pertain to
the actual call being connected, then hung up. The preceding lines are just
setting the caller id, and other related call-setup logging.
Is it common to have a dropped call being caused by asterisk? How would it show
up in the log? The only possible thing I can see in the logs, is the
"exited non-zero", which I've pasted here:
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Dialing '15053203372'
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Deferring dialing...
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Called g1/15053203372
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Sent deferred digit string:
T15053203372w
[Jun 21 08:53:32] VERBOSE[21559] logger.c: -- Zap/25-1 answered
SIP/611-b7b9ae38
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Hungup 'Zap/25-1'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' in
macro 'dialout-trunk'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38'
My experience is that with most programs, if they exit with a non-zero status,
that means that there was some kind of error. If that is the case, I cannot tell
what that would have been, based on the log.
As far a the log/verbose level is concerned, asterisk was started as
/usr/sbin/asterisk -vvvg
Here's the complete asterisk/full as it pertains to the given time period. I
do think that there are a few lines below that are relating to a different call,
which we're not concerned with.
[Jun 21 08:53:28] VERBOSE[22157] logger.c: Extension Changed 611[ext-local] new
state InUse for Notify User 610
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [5053203372 at
from-internal-NTC-custom:1] Macro("SIP/611-b7b9ae38",
"user-callerid|SKIPTTL|") in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:1] Set("SIP/611-b7b9ae38",
"AMPUSER=611") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:2] GotoIf("SIP/611-b7b9ae38",
"0?report") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:3] ExecIf("SIP/611-b7b9ae38",
"1|Set|REALCALLERIDNUM=611") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:4] Set("SIP/611-b7b9ae38",
"AMPUSER=611") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:5] Set("SIP/611-b7b9ae38",
"AMPUSERCIDNAME=Kurt") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:6] GotoIf("SIP/611-b7b9ae38",
"0?report") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:7] Set("SIP/611-b7b9ae38",
"AMPUSERCID=611") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:8] Set("SIP/611-b7b9ae38",
"CALLERID(all)="Kurt" <611>") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:9] Set("SIP/611-b7b9ae38",
"REALCALLERIDNUM=611") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:10] ExecIf("SIP/611-b7b9ae38",
"0|Set|CHANNEL(language)=") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:11] GotoIf("SIP/611-b7b9ae38",
"1?continue") in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Goto
(macro-user-callerid,s,20)
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-user-callerid:20] NoOp("SIP/611-b7b9ae38", "Using CallerID
"Kurt" <611>") in new stack
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Noop
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [5053203372 at
from-internal-NTC-custom:2] Set("SIP/611-b7b9ae38",
"_NODEST=") in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [5053203372 at
from-internal-NTC-custom:3] Macro("SIP/611-b7b9ae38",
"record-enable|611|OUT|") in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-record-enable:1] GotoIf("SIP/611-b7b9ae38", "1?check")
in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Goto (macro-record-enable,s,4)
[Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Executing [s at
macro-record-enable:4] AGI("SIP/611-b7b9ae38",
"recordingcheck|20100621-085328|1277132008.6419") in new stack
[Jun 21 08:53:28] VERBOSE[21559] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/recordingcheck
[Jun 21 08:53:29] VERBOSE[21559] logger.c:
recordingcheck|20100621-085328|1277132008.6419: Outbound recording not enabled
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- AGI Script recordingcheck
completed, returning 0
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: AGI
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-record-enable:5] MacroExit("SIP/611-b7b9ae38", "") in
new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [5053203372 at
from-internal-NTC-custom:4] Macro("SIP/611-b7b9ae38",
"dialout-trunk|2|5053203372||") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:1] Set("SIP/611-b7b9ae38",
"DIAL_TRUNK=2") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: AMPUSER/611/pinless not found in
database.
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:2] GosubIf("SIP/611-b7b9ae38",
"0?sub-pincheck|s|1") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GosubIf
[Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: AMPUSER/611/pinless not found in
database.
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:3] GotoIf("SIP/611-b7b9ae38",
"0?disabletrunk|1") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:4] Set("SIP/611-b7b9ae38",
"DIAL_NUMBER=5053203372") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:5] Set("SIP/611-b7b9ae38",
"DIAL_TRUNK_OPTIONS=tr") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:6] Set("SIP/611-b7b9ae38",
"OUTBOUND_GROUP=OUT_2") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:7] GotoIf("SIP/611-b7b9ae38", "1?nomax")
in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Goto (macro-dialout-trunk,s,9)
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:9] GotoIf("SIP/611-b7b9ae38",
"0?skipoutcid") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:10] Set("SIP/611-b7b9ae38",
"DIAL_TRUNK_OPTIONS=") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:11] Macro("SIP/611-b7b9ae38",
"outbound-callerid|2") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:1] ExecIf("SIP/611-b7b9ae38",
"0|SetCallerPres|") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:2] ExecIf("SIP/611-b7b9ae38",
"0|Set|REALCALLERIDNUM=611") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:3] GotoIf("SIP/611-b7b9ae38",
"1?normcid") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Goto
(macro-outbound-callerid,s,6)
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:6] Set("SIP/611-b7b9ae38",
"USEROUTCID=<5053251685>") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: DEVICE/611/emergency_cid not found
in database.
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:7] Set("SIP/611-b7b9ae38",
"EMERGENCYCID=") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:8] Set("SIP/611-b7b9ae38",
"TRUNKOUTCID=") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:9] GotoIf("SIP/611-b7b9ae38",
"1?trunkcid") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Goto
(macro-outbound-callerid,s,12)
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:12] ExecIf("SIP/611-b7b9ae38",
"0|Set|CALLERID(all)=") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:13] ExecIf("SIP/611-b7b9ae38",
"1|Set|CALLERID(all)=<5053251685>") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Last app:
Set|CALLERID(all)=<5053251685>
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-outbound-callerid:14] ExecIf("SIP/611-b7b9ae38",
"0|SetCallerPres|prohib_passed_screen") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Macro
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:12] ExecIf("SIP/611-b7b9ae38",
"1|AGI|fixlocalprefix") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Launched AGI Script
/var/lib/asterisk/agi-bin/fixlocalprefix
[Jun 21 08:53:29] VERBOSE[21559] logger.c: == fixlocalprefix: Dialpattern
1+NXXNXXXXXX matched. 5053203372 -> 15053203372
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- AGI Script fixlocalprefix
completed, returning 0
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Last app: AGI|fixlocalprefix
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:13] Set("SIP/611-b7b9ae38",
"OUTNUM=15053203372") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:14] Set("SIP/611-b7b9ae38",
"custom=ZAP/g1") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:15] ExecIf("SIP/611-b7b9ae38",
"0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:16] Macro("SIP/611-b7b9ae38",
"dialout-trunk-predial-hook|") in new stack
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk-predial-hook:1] MacroExit("SIP/611-b7b9ae38",
"") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Macro
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:17] GotoIf("SIP/611-b7b9ae38",
"0?bypass|1") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:18] GotoIf("SIP/611-b7b9ae38",
"0?customtrunk") in new stack
[Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Executing [s at
macro-dialout-trunk:19] Dial("SIP/611-b7b9ae38",
"ZAP/g1/15053203372|300|") in new stack
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Dialing '15053203372'
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Deferring dialing...
[Jun 21 08:53:29] VERBOSE[21559] logger.c: -- Called g1/15053203372
[Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Sent deferred digit string:
T15053203372w
[Jun 21 08:53:32] VERBOSE[21559] logger.c: -- Zap/25-1 answered
SIP/611-b7b9ae38
[Jun 21 08:53:42] VERBOSE[21484] logger.c: -- Executing [s at ivr-14:13]
WaitExten("Zap/1-1", "|") in new stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Hungup 'Zap/25-1'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' in
macro 'dialout-trunk'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [h at
macro-dialout-trunk:1] Macro("SIP/611-b7b9ae38",
"hangupcall|") in new stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:1] ResetCDR("SIP/611-b7b9ae38", "vw") in
new stack
[Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: ResetCDR
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:2] NoCDR("SIP/611-b7b9ae38", "") in new
stack
[Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: NoCDR
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:3] GotoIf("SIP/611-b7b9ae38", "1?skiprg")
in new stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Goto (macro-hangupcall,s,6)
[Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:6] GotoIf("SIP/611-b7b9ae38",
"1?skipblkvm") in new stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Goto (macro-hangupcall,s,9)
[Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:9] GotoIf("SIP/611-b7b9ae38", "1?theend")
in new stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Goto (macro-hangupcall,s,11)
[Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf
[Jun 21 08:53:56] VERBOSE[21559] logger.c: -- Executing [s at
macro-hangupcall:11] Hangup("SIP/611-b7b9ae38", "") in new
stack
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-hangupcall, s, 11) exited non-zero on 'SIP/611-b7b9ae38' in macro
'hangupcall'
[Jun 21 08:53:56] VERBOSE[21559] logger.c: == Spawn extension
(macro-hangupcall, s, 11) exited non-zero on 'SIP/611-b7b9ae38'
[Jun 21 08:53:56] VERBOSE[22157] logger.c: Extension Changed 611[ext-local] new
state Idle for Notify User 610
I appreciate your help and any suggestions on this.
Thanks,
-
Doug Mortensen
Network Consultant
Impala Networks Inc
CCNA, MCP, Security+, A+
Linux+, Network+, Server+
.
www.impalanetworks.com
P: (505) 327-7300
F: (505) 327-7545
dotnetdub
2010-Jun-21 18:08 UTC
[asterisk-users] How to tell if a dropped call is my fault
On Monday, June 21, 2010, Douglas Mortensen <doug at impalanetworks.com> wrote:> I just had a user report that they called out to someone on a cell phone this morning, and after a short conversation, the call was dropped/lost. The person on the cell phone says that this is very rare.Snip I really would suspect the cell phone. /611-b7b9ae38' in macro 'dialout-trunk'> [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' > > My experience is that with most programs, if they exit with a non-zero status, that means that there was some kind of error. If that is the case, I cannot tell what that would have been, based on the log. > > As far a the log/verbose level is concerned, asterisk was started as /usr/sbin/asterisk -vvvg > > Here's the complete asterisk/full as it pertains to the given time period. I do think that there are a few lines below that are relating to a different call, which we're not concerned with. > > [Jun 21 08:53:28] VERBOSE[22157] logger.c: ?Extension Changed 611[ext-local] new state InUse for Notify User 610 > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [5053203372 at from-internal-NTC-custom:1] Macro("SIP/611-b7b9ae38", "user-callerid|SKIPTTL|") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:1] Set("SIP/611-b7b9ae38", "AMPUSER=611") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:2] GotoIf("SIP/611-b7b9ae38", "0?report") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:3] ExecIf("SIP/611-b7b9ae38", "1|Set|REALCALLERIDNUM=611") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:4] Set("SIP/611-b7b9ae38", "AMPUSER=611") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:5] Set("SIP/611-b7b9ae38", "AMPUSERCIDNAME=Kurt") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:6] GotoIf("SIP/611-b7b9ae38", "0?report") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:7] Set("SIP/611-b7b9ae38", "AMPUSERCID=611") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:8] Set("SIP/611-b7b9ae38", "CALLERID(all)="Kurt" <611>") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:9] Set("SIP/611-b7b9ae38", "REALCALLERIDNUM=611") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:10] ExecIf("SIP/611-b7b9ae38", "0|Set|CHANNEL(language)=") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:11] GotoIf("SIP/611-b7b9ae38", "1?continue") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Goto (macro-user-callerid,s,20) > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-user-callerid:20] NoOp("SIP/611-b7b9ae38", "Using CallerID "Kurt" <611>") in new stack > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: Noop > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [5053203372 at from-internal-NTC-custom:2] Set("SIP/611-b7b9ae38", "_NODEST=") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [5053203372 at from-internal-NTC-custom:3] Macro("SIP/611-b7b9ae38", "record-enable|611|OUT|") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-record-enable:1] GotoIf("SIP/611-b7b9ae38", "1?check") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Goto (macro-record-enable,s,4) > [Jun 21 08:53:28] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-record-enable:4] AGI("SIP/611-b7b9ae38", "recordingcheck|20100621-085328|1277132008.6419") in new stack > [Jun 21 08:53:28] VERBOSE[21559] logger.c: ? ? -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? recordingcheck|20100621-085328|1277132008.6419: Outbound recording not enabled > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- AGI Script recordingcheck completed, returning 0 > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: AGI > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-record-enable:5] MacroExit("SIP/611-b7b9ae38", "") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [5053203372 at from-internal-NTC-custom:4] Macro("SIP/611-b7b9ae38", "dialout-trunk|2|5053203372||") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:1] Set("SIP/611-b7b9ae38", "DIAL_TRUNK=2") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: AMPUSER/611/pinless not found in database. > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:2] GosubIf("SIP/611-b7b9ae38", "0?sub-pincheck|s|1") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GosubIf > [Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: AMPUSER/611/pinless not found in database. > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:3] GotoIf("SIP/611-b7b9ae38", "0?disabletrunk|1") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:4] Set("SIP/611-b7b9ae38", "DIAL_NUMBER=5053203372") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:5] Set("SIP/611-b7b9ae38", "DIAL_TRUNK_OPTIONS=tr") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:6] Set("SIP/611-b7b9ae38", "OUTBOUND_GROUP=OUT_2") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:7] GotoIf("SIP/611-b7b9ae38", "1?nomax") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Goto (macro-dialout-trunk,s,9) > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:9] GotoIf("SIP/611-b7b9ae38", "0?skipoutcid") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:10] Set("SIP/611-b7b9ae38", "DIAL_TRUNK_OPTIONS=") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:11] Macro("SIP/611-b7b9ae38", "outbound-callerid|2") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:1] ExecIf("SIP/611-b7b9ae38", "0|SetCallerPres|") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:2] ExecIf("SIP/611-b7b9ae38", "0|Set|REALCALLERIDNUM=611") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:3] GotoIf("SIP/611-b7b9ae38", "1?normcid") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Goto (macro-outbound-callerid,s,6) > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:6] Set("SIP/611-b7b9ae38", "USEROUTCID=<5053251685>") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] DEBUG[21559] func_db.c: DB: DEVICE/611/emergency_cid not found in database. > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:7] Set("SIP/611-b7b9ae38", "EMERGENCYCID=") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:8] Set("SIP/611-b7b9ae38", "TRUNKOUTCID=") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:9] GotoIf("SIP/611-b7b9ae38", "1?trunkcid") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Goto (macro-outbound-callerid,s,12) > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:12] ExecIf("SIP/611-b7b9ae38", "0|Set|CALLERID(all)=") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:13] ExecIf("SIP/611-b7b9ae38", "1|Set|CALLERID(all)=<5053251685>") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Last app: Set|CALLERID(all)=<5053251685> > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-outbound-callerid:14] ExecIf("SIP/611-b7b9ae38", "0|SetCallerPres|prohib_passed_screen") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Macro > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:12] ExecIf("SIP/611-b7b9ae38", "1|AGI|fixlocalprefix") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? == ?fixlocalprefix: Dialpattern 1+NXXNXXXXXX matched. 5053203372 -> 15053203372 > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- AGI Script fixlocalprefix completed, returning 0 > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Last app: AGI|fixlocalprefix > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:13] Set("SIP/611-b7b9ae38", "OUTNUM=15053203372") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:14] Set("SIP/611-b7b9ae38", "custom=ZAP/g1") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Set > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:15] ExecIf("SIP/611-b7b9ae38", "0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: ExecIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:16] Macro("SIP/611-b7b9ae38", "dialout-trunk-predial-hook|") in new stack > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk-predial-hook:1] MacroExit("SIP/611-b7b9ae38", "") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: Macro > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:17] GotoIf("SIP/611-b7b9ae38", "0?bypass|1") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:18] GotoIf("SIP/611-b7b9ae38", "0?customtrunk") in new stack > [Jun 21 08:53:29] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-dialout-trunk:19] Dial("SIP/611-b7b9ae38", "ZAP/g1/15053203372|300|") in new stack > [Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Dialing '15053203372' > [Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Deferring dialing... > [Jun 21 08:53:29] VERBOSE[21559] logger.c: ? ? -- Called g1/15053203372 > [Jun 21 08:53:29] DEBUG[21559] chan_zap.c: Sent deferred digit string: T15053203372w > [Jun 21 08:53:32] VERBOSE[21559] logger.c: ? ? -- Zap/25-1 answered SIP/611-b7b9ae38 > [Jun 21 08:53:42] VERBOSE[21484] logger.c: ? ? -- Executing [s at ivr-14:13] WaitExten("Zap/1-1", "|") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Hungup 'Zap/25-1' > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' in macro 'dialout-trunk' > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/611-b7b9ae38' > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [h at macro-dialout-trunk:1] Macro("SIP/611-b7b9ae38", "hangupcall|") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:1] ResetCDR("SIP/611-b7b9ae38", "vw") in new stack > [Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: ResetCDR > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:2] NoCDR("SIP/611-b7b9ae38", "") in new stack > [Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: NoCDR > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:3] GotoIf("SIP/611-b7b9ae38", "1?skiprg") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Goto (macro-hangupcall,s,6) > [Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:6] GotoIf("SIP/611-b7b9ae38", "1?skipblkvm") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Goto (macro-hangupcall,s,9) > [Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:9] GotoIf("SIP/611-b7b9ae38", "1?theend") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Goto (macro-hangupcall,s,11) > [Jun 21 08:53:56] DEBUG[21559] app_macro.c: Executed application: GotoIf > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? ? -- Executing [s at macro-hangupcall:11] Hangup("SIP/611-b7b9ae38", "") in new stack > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/611-b7b9ae38' in macro 'hangupcall' > [Jun 21 08:53:56] VERBOSE[21559] logger.c: ? == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/611-b7b9ae38' > [Jun 21 08:53:56] VERBOSE[22157] logger.c: ?Extension Changed 611[ext-local] new state Idle for Notify User 610 > > > I appreciate your help and any suggestions on this. > > Thanks, > - > Doug Mortensen > Network Consultant > Impala Networks Inc > CCNA, MCP, Security+, A+ > Linux+, Network+, Server+ > . > www.impalanetworks.com > P: (505) 327-7300 > F: (505) 327-7545 > > > > -- > _____________________________________________________________________ > -- Bandwidth and Colocation Provided by http://www.api-digital.com -- > New to Asterisk? Join us for a live introductory webinar every Thurs: > ? ? ? ? ? ? ? http://www.asterisk.org/hello > > asterisk-users mailing list > To UNSUBSCRIBE or update options visit: > ? ?<http://lists.digium.com/mailman/listinfo/asterisk-users>