ZAP extension omitting 1 from dial string

Discussion in 'General' started by vtofa, Apr 1, 2009.

  1. vtofa

    Joined:
    Oct 21, 2008
    Messages:
    67
    Likes Received:
    0
    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!
     
  2. vtofa

    Joined:
    Oct 21, 2008
    Messages:
    67
    Likes Received:
    0
    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'
    
     
  3. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
    make sure immediate=no in zapata.conf
     
  4. vtofa

    Joined:
    Oct 21, 2008
    Messages:
    67
    Likes Received:
    0
    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
     
  5. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
    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
     
  6. vtofa

    Joined:
    Oct 21, 2008
    Messages:
    67
    Likes Received:
    0
    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!
     
  7. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
  8. vtofa

    Joined:
    Oct 21, 2008
    Messages:
    67
    Likes Received:
    0
    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?
     
  9. dicko

    Joined:
    Oct 24, 2008
    Messages:
    4,099
    Likes Received:
    0
    [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.
     

Share This Page