ZAP extension omitting 1 from dial string

vtofa

Joined
Oct 21, 2008
Messages
67
Likes
0
Points
0
#1
I'm having a problem with a ZAP device dropping the digit '1' from the dial string. That makes it impossible to dial a long distance number.

in this case I have a Sangoma card with both FXO and FXS interfaces, so the call goes in from the FXS and goes out to the PSTN through the FXO.

Any ideas what might be happening?

Thanks!
 

vtofa

Joined
Oct 21, 2008
Messages
67
Likes
0
Points
0
#2
The puzzling thing is that it sometimes works. Here's /var/log/asterisk/full for both working, and non-working. Any ideas would be appreciated.

First log output for when it works:

Code:
WORKS:

[Apr  1 10:14:33] VERBOSE[23079] logger.c:     -- Starting simple switch on 'Zap/5-1'
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [15032962051@from-internal:1] Macro("Zap/5-1", "user-callerid|SKIPTTL|") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:1] NoOp("Zap/5-1", "user-callerid: Channel 5 6005") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:2] Set("Zap/5-1", "AMPUSER=6005") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:3] GotoIf("Zap/5-1", "0?report") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:4] ExecIf("Zap/5-1", "1|Set|REALCALLERIDNUM=6005") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: ExecIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:5] NoOp("Zap/5-1", "REALCALLERIDNUM is 6005") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: DEVICE/6005/user not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:6] Set("Zap/5-1", "AMPUSER=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: AMPUSER//cidname not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:7] Set("Zap/5-1", "AMPUSERCIDNAME=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:8] GotoIf("Zap/5-1", "1?report") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-user-callerid,s,13)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:13] NoOp("Zap/5-1", "TTL:  ARG1: SKIPTTL") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:14] GotoIf("Zap/5-1", "1?continue") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-user-callerid,s,23)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-user-callerid:23] NoOp("Zap/5-1", "Using CallerID "Channel 5" <6005>") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [15032962051@from-internal:2] Set("Zap/5-1", "_NODEST=") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [15032962051@from-internal:3] Macro("Zap/5-1", "record-enable||OUT|") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-record-enable:1] GotoIf("Zap/5-1", "0?2:4") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-record-enable,s,4)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-record-enable:4] AGI("Zap/5-1", "recordingcheck|20090401-101442|1238606073.878") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Apr  1 10:14:42] VERBOSE[23079] logger.c:   recordingcheck|20090401-101442|1238606073.878: No AMPUSER db entry for . Not recording
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- AGI Script recordingcheck completed, returning 0
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: AGI
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-record-enable:5] NoOp("Zap/5-1", "No recording needed") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [15032962051@from-internal:4] Macro("Zap/5-1", "dialout-trunk|1|15032962051||") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:1] Set("Zap/5-1", "DIAL_TRUNK=1") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: AMPUSER//pinless not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:2] ExecIf("Zap/5-1", "0|Authenticate|") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: ExecIf
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: AMPUSER//pinless not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:3] GotoIf("Zap/5-1", "0?disabletrunk|1") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:4] Set("Zap/5-1", "DIAL_NUMBER=15032962051") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:5] Set("Zap/5-1", "DIAL_TRUNK_OPTIONS=tr") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:6] Set("Zap/5-1", "GROUP()=OUT_1") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:7] GotoIf("Zap/5-1", "1?nomax") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-dialout-trunk,s,9)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:9] GotoIf("Zap/5-1", "0?skipoutcid") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:10] Set("Zap/5-1", "DIAL_TRUNK_OPTIONS=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:11] Macro("Zap/5-1", "outbound-callerid|1") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:1] ExecIf("Zap/5-1", "0|SetCallerPres|") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: ExecIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:2] GotoIf("Zap/5-1", "1?start") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-outbound-callerid,s,4)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:4] NoOp("Zap/5-1", "REALCALLERIDNUM is 6005") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:5] GotoIf("Zap/5-1", "1?normcid") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-outbound-callerid,s,10)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: AMPUSER/6005/outboundcid not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:10] Set("Zap/5-1", "USEROUTCID=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] DEBUG[23079] func_db.c: DB: DEVICE/6005/emergency_cid not found in database.
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:11] Set("Zap/5-1", "EMERGENCYCID=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:12] Set("Zap/5-1", "TRUNKOUTCID=") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:13] GotoIf("Zap/5-1", "1?trunkcid") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-outbound-callerid,s,17)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:17] GotoIf("Zap/5-1", "1?usercid") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-outbound-callerid,s,19)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:19] GotoIf("Zap/5-1", "1?report") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-outbound-callerid,s,23)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-outbound-callerid:23] NoOp("Zap/5-1", "CallerID set to "Channel 5" <6005>") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Noop
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Macro
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:12] AGI("Zap/5-1", "fixlocalprefix") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- AGI Script fixlocalprefix completed, returning 0
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: AGI
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:13] Set("Zap/5-1", "OUTNUM=15032962051") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:14] Set("Zap/5-1", "custom=ZAP/g0") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Set
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:15] GotoIf("Zap/5-1", "1?gocall") in new stack
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Goto (macro-dialout-trunk,s,17)
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:17] Macro("Zap/5-1", "dialout-trunk-predial-hook|") in new stack
[Apr  1 10:14:42] WARNING[23079] app_macro.c: Context 'macro-dialout-trunk-predial-hook' for macro 'dialout-trunk-predial-hook' lacks 's' extension, priority 1
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: Macro
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:18] GotoIf("Zap/5-1", "0?bypass|1") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:19] GotoIf("Zap/5-1", "0?customtrunk") in new stack
[Apr  1 10:14:42] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Executing [s@macro-dialout-trunk:20] Dial("Zap/5-1", "ZAP/g0/15032962051|300|") in new stack
[Apr  1 10:14:42] DEBUG[23079] chan_dahdi.c: Dialing '15032962051'
[Apr  1 10:14:42] DEBUG[23079] chan_dahdi.c: Deferring dialing...
[Apr  1 10:14:42] VERBOSE[23079] logger.c:     -- Called g0/15032962051
[Apr  1 10:14:43] DEBUG[23079] chan_dahdi.c: Sent deferred digit string: T1503296205
[Apr  1 10:14:45] WARNING[23079] chan_dahdi.c: Unable to request echo training on channel 1: Invalid argument
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Echo cancellation already on
[Apr  1 10:14:47] VERBOSE[23079] logger.c:     -- Zap/1-1 answered Zap/5-1
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Took Zap/5-1 off hook
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: master: 5, slave: 1, nothingok: 0
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Stopping tones on 5/0 talking to 1/0
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Stopping tones on 1/0 talking to 5/0
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Making 1 slave to master 5 at 0
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Added 16 to conference 9/5
[Apr  1 10:14:47] DEBUG[23079] chan_dahdi.c: Added 20 to conference 9/1
[Apr  1 10:14:47] VERBOSE[23079] logger.c:     -- Native bridging Zap/5-1 and Zap/1-1
[Apr  1 10:14:53] DEBUG[23079] chan_dahdi.c: Unlinking slave 1 from 5
[Apr  1 10:14:53] DEBUG[23079] chan_dahdi.c: Removed 16 from conference 9/5
[Apr  1 10:14:53] DEBUG[23079] chan_dahdi.c: Removed 20 from conference 9/1
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Hungup 'Zap/1-1'
[Apr  1 10:14:53] VERBOSE[23079] logger.c:   == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Zap/5-1' in macro 'dialout-trunk'
[Apr  1 10:14:53] VERBOSE[23079] logger.c:   == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Zap/5-1'
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [h@macro-dialout-trunk:1] Macro("Zap/5-1", "hangupcall|") in new stack
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:1] ResetCDR("Zap/5-1", "w") in new stack
[Apr  1 10:14:53] DEBUG[23079] app_macro.c: Executed application: ResetCDR
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:2] NoCDR("Zap/5-1", "") in new stack
[Apr  1 10:14:53] DEBUG[23079] app_macro.c: Executed application: NoCDR
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:3] GotoIf("Zap/5-1", "1?skiprg") in new stack
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Goto (macro-hangupcall,s,6)
[Apr  1 10:14:53] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:6] GotoIf("Zap/5-1", "1?skipblkvm") in new stack
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Goto (macro-hangupcall,s,9)
[Apr  1 10:14:53] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:9] GotoIf("Zap/5-1", "1?theend") in new stack
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Goto (macro-hangupcall,s,11)
[Apr  1 10:14:53] DEBUG[23079] app_macro.c: Executed application: GotoIf
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Executing [s@macro-hangupcall:11] Hangup("Zap/5-1", "") in new stack
[Apr  1 10:14:53] VERBOSE[23079] logger.c:   == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Zap/5-1' in macro 'hangupcall'
[Apr  1 10:14:53] VERBOSE[23079] logger.c:   == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Zap/5-1'
[Apr  1 10:14:53] VERBOSE[23079] logger.c:     -- Hungup 'Zap/5-1'
[Apr  1 10:14:57] DEBUG[3086] chan_dahdi.c: Message status for 6005 changed from -1 to 0 on 5
Then non-working
Code:
DOESN'T WORK

[Apr  1 10:18:55] NOTICE[3069] chan_iax2.c: Restricting registration for peer '50' to 60 seconds (requested 300)
[Apr  1 10:19:36] VERBOSE[23101] logger.c:     -- Starting simple switch on 'Zap/5-1'
[Apr  1 10:19:43] NOTICE[23101] chan_dahdi.c: Fax detected, but no fax extension
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [5032962051@from-internal:1] Macro("Zap/5-1", "user-callerid|SKIPTTL|") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:1] NoOp("Zap/5-1", "user-callerid: Channel 5 6005") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:2] Set("Zap/5-1", "AMPUSER=6005") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:3] GotoIf("Zap/5-1", "0?report") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:4] ExecIf("Zap/5-1", "1|Set|REALCALLERIDNUM=6005") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: ExecIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:5] NoOp("Zap/5-1", "REALCALLERIDNUM is 6005") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: DEVICE/6005/user not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:6] Set("Zap/5-1", "AMPUSER=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: AMPUSER//cidname not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:7] Set("Zap/5-1", "AMPUSERCIDNAME=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:8] GotoIf("Zap/5-1", "1?report") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-user-callerid,s,13)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:13] NoOp("Zap/5-1", "TTL:  ARG1: SKIPTTL") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:14] GotoIf("Zap/5-1", "1?continue") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-user-callerid,s,23)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-user-callerid:23] NoOp("Zap/5-1", "Using CallerID "Channel 5" <6005>") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [5032962051@from-internal:2] Set("Zap/5-1", "_NODEST=") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [5032962051@from-internal:3] Macro("Zap/5-1", "record-enable||OUT|") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-record-enable:1] GotoIf("Zap/5-1", "0?2:4") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-record-enable,s,4)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-record-enable:4] AGI("Zap/5-1", "recordingcheck|20090401-101945|1238606376.887") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Apr  1 10:19:45] VERBOSE[23101] logger.c:   recordingcheck|20090401-101945|1238606376.887: No AMPUSER db entry for . Not recording
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- AGI Script recordingcheck completed, returning 0
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: AGI
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-record-enable:5] NoOp("Zap/5-1", "No recording needed") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [5032962051@from-internal:4] Macro("Zap/5-1", "dialout-trunk|1|5032962051||") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:1] Set("Zap/5-1", "DIAL_TRUNK=1") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: AMPUSER//pinless not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:2] ExecIf("Zap/5-1", "0|Authenticate|") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: ExecIf
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: AMPUSER//pinless not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:3] GotoIf("Zap/5-1", "0?disabletrunk|1") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:4] Set("Zap/5-1", "DIAL_NUMBER=5032962051") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:5] Set("Zap/5-1", "DIAL_TRUNK_OPTIONS=tr") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:6] Set("Zap/5-1", "GROUP()=OUT_1") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:7] GotoIf("Zap/5-1", "1?nomax") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-dialout-trunk,s,9)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:9] GotoIf("Zap/5-1", "0?skipoutcid") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:10] Set("Zap/5-1", "DIAL_TRUNK_OPTIONS=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:11] Macro("Zap/5-1", "outbound-callerid|1") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:1] ExecIf("Zap/5-1", "0|SetCallerPres|") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: ExecIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:2] GotoIf("Zap/5-1", "1?start") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-outbound-callerid,s,4)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:4] NoOp("Zap/5-1", "REALCALLERIDNUM is 6005") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:5] GotoIf("Zap/5-1", "1?normcid") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-outbound-callerid,s,10)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: AMPUSER/6005/outboundcid not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:10] Set("Zap/5-1", "USEROUTCID=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] DEBUG[23101] func_db.c: DB: DEVICE/6005/emergency_cid not found in database.
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:11] Set("Zap/5-1", "EMERGENCYCID=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:12] Set("Zap/5-1", "TRUNKOUTCID=") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:13] GotoIf("Zap/5-1", "1?trunkcid") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-outbound-callerid,s,17)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:17] GotoIf("Zap/5-1", "1?usercid") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-outbound-callerid,s,19)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:19] GotoIf("Zap/5-1", "1?report") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-outbound-callerid,s,23)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-outbound-callerid:23] NoOp("Zap/5-1", "CallerID set to "Channel 5" <6005>") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Noop
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Macro
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:12] AGI("Zap/5-1", "fixlocalprefix") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- AGI Script fixlocalprefix completed, returning 0
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: AGI
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:13] Set("Zap/5-1", "OUTNUM=5032962051") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:14] Set("Zap/5-1", "custom=ZAP/g0") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Set
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:15] GotoIf("Zap/5-1", "1?gocall") in new stack
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Goto (macro-dialout-trunk,s,17)
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:17] Macro("Zap/5-1", "dialout-trunk-predial-hook|") in new stack
[Apr  1 10:19:45] WARNING[23101] app_macro.c: Context 'macro-dialout-trunk-predial-hook' for macro 'dialout-trunk-predial-hook' lacks 's' extension, priority 1
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: Macro
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:18] GotoIf("Zap/5-1", "0?bypass|1") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:19] GotoIf("Zap/5-1", "0?customtrunk") in new stack
[Apr  1 10:19:45] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Executing [s@macro-dialout-trunk:20] Dial("Zap/5-1", "ZAP/g0/5032962051|300|") in new stack
[Apr  1 10:19:45] DEBUG[23101] chan_dahdi.c: Dialing '5032962051'
[Apr  1 10:19:45] DEBUG[23101] chan_dahdi.c: Deferring dialing...
[Apr  1 10:19:45] VERBOSE[23101] logger.c:     -- Called g0/5032962051
[Apr  1 10:19:46] DEBUG[23101] chan_dahdi.c: Sent deferred digit string: T503296205
[Apr  1 10:19:47] WARNING[23101] chan_dahdi.c: Unable to request echo training on channel 1: Invalid argument
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Echo cancellation already on
[Apr  1 10:19:50] VERBOSE[23101] logger.c:     -- Zap/1-1 answered Zap/5-1
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Took Zap/5-1 off hook
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: master: 5, slave: 1, nothingok: 0
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Stopping tones on 5/0 talking to 1/0
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Stopping tones on 1/0 talking to 5/0
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Making 1 slave to master 5 at 0
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Added 16 to conference 9/5
[Apr  1 10:19:50] DEBUG[23101] chan_dahdi.c: Added 20 to conference 9/1
[Apr  1 10:19:50] VERBOSE[23101] logger.c:     -- Native bridging Zap/5-1 and Zap/1-1
[Apr  1 10:19:50] NOTICE[3076] chan_iax2.c: Restricting registration for peer '50' to 60 seconds (requested 300)
[Apr  1 10:19:58] DEBUG[23101] chan_dahdi.c: Unlinking slave 1 from 5
[Apr  1 10:19:58] DEBUG[23101] chan_dahdi.c: Removed 16 from conference 9/5
[Apr  1 10:19:58] DEBUG[23101] chan_dahdi.c: Removed 20 from conference 9/1
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Hungup 'Zap/1-1'
[Apr  1 10:19:58] VERBOSE[23101] logger.c:   == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Zap/5-1' in macro 'dialout-trunk'
[Apr  1 10:19:58] VERBOSE[23101] logger.c:   == Spawn extension (macro-dialout-trunk, s, 20) exited non-zero on 'Zap/5-1'
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [h@macro-dialout-trunk:1] Macro("Zap/5-1", "hangupcall|") in new stack
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:1] ResetCDR("Zap/5-1", "w") in new stack
[Apr  1 10:19:58] DEBUG[23101] app_macro.c: Executed application: ResetCDR
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:2] NoCDR("Zap/5-1", "") in new stack
[Apr  1 10:19:58] DEBUG[23101] app_macro.c: Executed application: NoCDR
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:3] GotoIf("Zap/5-1", "1?skiprg") in new stack
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Goto (macro-hangupcall,s,6)
[Apr  1 10:19:58] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:6] GotoIf("Zap/5-1", "1?skipblkvm") in new stack
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Goto (macro-hangupcall,s,9)
[Apr  1 10:19:58] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:9] GotoIf("Zap/5-1", "1?theend") in new stack
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Goto (macro-hangupcall,s,11)
[Apr  1 10:19:58] DEBUG[23101] app_macro.c: Executed application: GotoIf
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Executing [s@macro-hangupcall:11] Hangup("Zap/5-1", "") in new stack
[Apr  1 10:19:58] VERBOSE[23101] logger.c:   == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Zap/5-1' in macro 'hangupcall'
[Apr  1 10:19:58] VERBOSE[23101] logger.c:   == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'Zap/5-1'
[Apr  1 10:19:58] VERBOSE[23101] logger.c:     -- Hungup 'Zap/5-1'
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#3
make sure immediate=no in zapata.conf
 

vtofa

Joined
Oct 21, 2008
Messages
67
Likes
0
Points
0
#4
It is. Here's the zapata.conf

[trunkgroups]

[channels]
context=from-pstn
signalling=fxs_ks
rxwink=300 ; Atlas seems to use long (250ms) winks
usecallerid=yes
hidecallerid=no
callwaiting=yes
usecallingpres=yes
callwaitingcallerid=yes
threewaycalling=yes
transfer=yes
canpark=yes
cancallforward=yes
callreturn=yes
echocancel=yes
echocancelwhenbridged=no
faxdetect=incoming
echotraining=800
rxgain=0.0
txgain=0.0
callgroup=1
pickupgroup=1

;Uncomment these lines if you have problems with the disconection of your analog lines
;busydetect=yes
;busycount=3


immediate=no

#include zapata_additional.conf
#include zapata-channels.conf
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#5
and not overridden in the included zapata files?
#include zapata_additional.conf
#include zapata-channels.conf

(I say this because if immediate=yes, then the zap driver does not wait for dial tone before dialing, possibly swallowing the first digit (changes to zapata files take an asterisk restart to take effect)

also this snip is interesting
.
[Apr 1 10:19:36] VERBOSE[23101] logger.c: -- Starting simple switch on 'Zap/5-1'
[Apr 1 10:19:43] NOTICE[23101] chan_dahdi.c: Fax detected, but no fax extension
[Apr 1 10:19:45] VERBOSE[23101] logger.c: -- Executing [5032962051@from-internal:1] Macro("Zap/5-1", "user-. .
.
.

apparently your'e system is mis-identifying apparent fax tones on the channel (a variety of talk-off),
I suggest you turn all fax detection off in the zapata files

faxdetect=no
 

vtofa

Joined
Oct 21, 2008
Messages
67
Likes
0
Points
0
#6
thanks dicko,
It is not overridden in the includes.

If I turn of fax detection in zapata.conf, will it disable my hylafax extension?

Thanks!
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#7
No
 

vtofa

Joined
Oct 21, 2008
Messages
67
Likes
0
Points
0
#8
Faxdetect didn't help.
But a closer look at the log reveals this:

[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Executing [5032962051@from-int ernal:4] Macro("Zap/5-1", "dialout-trunk|1|5032962051||") in new stack
[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Executing [s@macro-dialout-tru nk:1] Set("Zap/5-1", "DIAL_TRUNK=1") in new stack

<snip>

[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Executing [s@macro-dialout-tru nk:12] AGI("Zap/5-1", "fixlocalprefix") in new stack
[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Launched AGI Script /var/lib/a sterisk/agi-bin/fixlocalprefix
[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- AGI Script fixlocalprefix comp leted, returning 0
[Apr 1 17:00:02] DEBUG[24349] app_macro.c: Executed application: AGI
[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Executing [s@macro-dialout-tru nk:13] Set("Zap/5-1", "OUTNUM=5032962051") in new stack

Seems like it might be thinking that it needs to take the 1 out, because it might be thinking that it is a local number, rather than a long distance number.

What to look for?
 

dicko

Joined
Oct 24, 2008
Messages
4,099
Likes
0
Points
0
#9
[Apr 1 17:00:02] VERBOSE[24349] logger.c: -- Executing [5032962051@from-internal:4] Macro("Zap/5-1", "dialout-trunk|1|5032962051||" in new stack

means that 5032962051 is the extent of the dtmf's asterisk determined that was dialed, it is missing the initial, "1" even here, that and the fax misinterpretation, have you used different hardware, maybe a broken dialpad on the handset? start with a basic $5 walmart touch-tone analog phone and listen carefully first for uninterrupted dialtone, then your dtmf tones being sent clearly. (nothing else should be heard) if that passes the test I would suspect the fxo/s hardware or channel driver even.



Of course
1NXXNXXXXXX = ld
NXXXXXX = local in oregon no?

it is always better to use explicit patterns in outgoing routes and trunks eliminate rather than rely on ".", but I don't think that's your problem.
 

Members online

No members online now.

Latest posts

Forum statistics

Threads
30,902
Messages
130,887
Members
17,567
Latest member
achilont13
Top