Zaptel Not Answering After Upgrade

I recently upgraded from 1.2.26 to 1.4.21 and zaptel code as well. At the same time I upgraded FreePBX to the latest version to 2.4.1.0. The problem is that incoming zaptel calls on the TDM400 aren’t working correctly. SIP calls come in just fine. The call shows that it is being answered but Asterisk shows it hanging up immediately. The caller just hears continued ringing. Any idea why this is happening?

[Jul 19 02:15:37] VERBOSE[5386] logger.c: – Starting simple switch on ‘Zap/2-1’
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:1] NoOp(“Zap/2-1”, "Entering from-zaptel with DID == “) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Ringing(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:3] Set(“Zap/2-1”, “DID=s”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:4] NoOp(“Zap/2-1”, “DID is now s”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:5] GotoIf(“Zap/2-1”, “1?zapok:notzap”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Goto (from-zaptel,s,Cool
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:8] NoOp(“Zap/2-1”, “Is a Zaptel Channel”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [[email protected]:9] Set(“Zap/2-1”, “CHAN=2-1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:10] Set(“Zap/2-1”, “CHAN=2”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:11] Macro(“Zap/2-1”, “from-zaptel-2|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] NoOp(“Zap/2-1”, “Entering macro-from-zaptel-2 with DID = s and setting to: zapchan2”) in new stack
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Noop
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Set(“Zap/2-1”, “__FROM_DID=zapchan2”) in new stack
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Set
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] Goto(“Zap/2-1”, “from-trunk|zapchan2|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (from-trunk,zapchan2,1)
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Goto
[Jul 19 02:15:39] VERBOSE[5386] logger.c: == Channel ‘Zap/2-1’ jumping out of macro ‘from-zaptel-2’
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] Set(“Zap/2-1”, “__FROM_DID=zapchan2”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] LookupBlacklist(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] Return(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] GotoIf(“Zap/2-1”, “0 ?cidok”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:4] Set(“Zap/2-1”, “CALLERID(name)=9009002685”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:5] NoOp(“Zap/2-1”, “CallerID is “9009002685” <9009002685>”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:6] Set(“Zap/2-1”, "[email protected]”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:7] Answer(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] DEBUG[5386] chan_zap.c: Took Zap/2-1 off hook
[Jul 19 02:15:39] DEBUG[5386] chan_zap.c: Engaged echo training on channel 2
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:8] PlayTones(“Zap/2-1”, “ring”) in new stack
[Jul 19 02:15:39] WARNING[5386] pbx.c: No application ‘NVFaxDetect’ for extension (from-trunk, zapchan2, 9)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: == Spawn extension (from-trunk, zapchan2, 9) exited non-zero on ‘Zap/2-1’
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] NoOp(“Zap/2-1”, “Catch-All DID Match - Found h - You probably want a DID for this.”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Goto(“Zap/2-1”, “ext-did|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (ext-did,s,1)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] Set(“Zap/2-1”, “__FROM_DID=s”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] LookupBlacklist(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] Return(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] GotoIf(“Zap/2-1”, “1 ?cidok”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (ext-did,s,5)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:5] NoOp(“Zap/2-1”, “CallerID is “9009002685” <9009002685>”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:6] Set(“Zap/2-1”, “FAX_RX=system”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:7] Set(“Zap/2-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:8] SetCallerPres(“Zap/2-1”, “allowed_not_screened”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:9] Goto(“Zap/2-1”, “from-did-direct|110|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (from-did-direct,110,1)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] GotoIf(“Zap/2-1”, “0?ext-local|110|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Macro(“Zap/2-1”, “user-callerid|”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] NoOp(“Zap/2-1”, “user-callerid: 9009002685 9009002685”) in new stack
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Noop
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Extension s, macroexten 110, priority 1 returned normally even though call was hung up
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:3] GotoIf(“Zap/2-1”, “1?skipdb”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (from-did-direct,110,5)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:5] Set(“Zap/2-1”, “__NODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:6] Set(“Zap/2-1”, “__BLKVM_OVERRIDE=BLKVM/110/Zap/2-1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:7] Set(“Zap/2-1”, “__BLKVM_BASE=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:8] Set(“Zap/2-1”, “DB(BLKVM/110/Zap/2-1)=TRUE”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:9] Set(“Zap/2-1”, “RRNODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:10] Set(“Zap/2-1”, “__NODEST=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:11] GotoIf(“Zap/2-1”, “1 ?skipsimple”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (from-did-direct,110,13)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]did-direct:13] Set(“Zap/2-1”, “RecordMethod=Group”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:14] Macro(“Zap/2-1”, “record-enable|110-1001|Group”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] GotoIf(“Zap/2-1”, “0?2:4”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (macro-record-enable,s,4)
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: GotoIf
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Extension s, macroexten 110, priority 3 returned normally even though call was hung up
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:15] Set(“Zap/2-1”, “RingGroupMethod=ringall”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:16] Set(“Zap/2-1”, “_FMGRP=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:17] GotoIf(“Zap/2-1”, “0?doconfirm”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:18] Macro(“Zap/2-1”, “dial|20|tr|110-1001”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] GotoIf(“Zap/2-1”, “1?dial”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (macro-dial,s,3)
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: GotoIf
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Extension s, macroexten 110, priority 2 returned normally even though call was hung up
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:19] Goto(“Zap/2-1”, “nextstep”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (from-did-direct,110,21)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:21] Set(“Zap/2-1”, “RingGroupMethod=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:22] GotoIf(“Zap/2-1”, “0?nodest”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:23] Set(“Zap/2-1”, “__NODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:24] DBdel(“Zap/2-1”, “BLKVM/110/Zap/2-1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – DBdel: family=BLKVM, key=110/Zap/2-1
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:25] Goto(“Zap/2-1”, “ext-local|vmu110|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Goto (ext-local,vmu110,1)
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] Macro(“Zap/2-1”, “vm|110|NOANSWER”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] Macro(“Zap/2-1”, “user-callerid|SKIPTTL”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:1] NoOp(“Zap/2-1”, “user-callerid: 9009002685 9009002685”) in new stack
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Noop
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Extension s, macroexten vmu110, priority 1 returned normally even though call was hung up
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Executed application: Macro
[Jul 19 02:15:39] DEBUG[5386] app_macro.c: Extension s, macroexten vmu110, priority 1 returned normally even though call was hung up
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [[email protected]:2] Hangup(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: == Spawn extension (ext-local, vmu110, 2) exited non-zero on ‘Zap/2-1’
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Hungup ‘Zap/2-1’