Zaptel on 1.4 not Answering Properly

I recently upgraded from 1.2.26 to 1.4.21 and zaptel code as well. 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 [s@from-zaptel:1] NoOp(“Zap/2-1”, "Entering from-zaptel with DID == “) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:2] Ringing(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:3] Set(“Zap/2-1”, “DID=s”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:4] NoOp(“Zap/2-1”, “DID is now s”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:5] GotoIf(“Zap/2-1”, “1?zapok:notzap”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Goto (from-zaptel,s,8)
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:8] NoOp(“Zap/2-1”, “Is a Zaptel Channel”) in new stack
[Jul 19 02:15:38] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:9] Set(“Zap/2-1”, “CHAN=2-1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:10] Set(“Zap/2-1”, “CHAN=2”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@from-zaptel:11] Macro(“Zap/2-1”, “from-zaptel-2|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-from-zaptel-2: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 [s@macro-from-zaptel-2: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 [s@macro-from-zaptel-2: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 [zapchan2@from-trunk:1] Set(“Zap/2-1”, “__FROM_DID=zapchan2”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk:2] Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:3] Return(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk:3] GotoIf(“Zap/2-1”, “0 ?cidok”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk:4] Set(“Zap/2-1”, “CALLERID(name)=9009002685”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk:5] NoOp(“Zap/2-1”, “CallerID is “9009002685” <9009002685>”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk:6] Set(“Zap/2-1”, "FAX_RX_EMAIL=fax@believewireless.net”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [zapchan2@from-trunk: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 [zapchan2@from-trunk: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 [h@from-trunk: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 [h@from-trunk: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 [s@ext-did:1] Set(“Zap/2-1”, “__FROM_DID=s”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did:2] Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@app-blacklist-check:3] Return(“Zap/2-1”, “”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did: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 [s@ext-did:5] NoOp(“Zap/2-1”, “CallerID is “9009002685” <9009002685>”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did:6] Set(“Zap/2-1”, “FAX_RX=system”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did:7] Set(“Zap/2-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did:8] SetCallerPres(“Zap/2-1”, “allowed_not_screened”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@ext-did: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 [110@from-did-direct:1] GotoIf(“Zap/2-1”, “0?ext-local|110|1”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:2] Macro(“Zap/2-1”, “user-callerid|”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-user-callerid: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 [110@from-did-direct: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 [110@from-did-direct:5] Set(“Zap/2-1”, “__NODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct: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 [110@from-did-direct:7] Set(“Zap/2-1”, “__BLKVM_BASE=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct: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 [110@from-did-direct:9] Set(“Zap/2-1”, “RRNODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:10] Set(“Zap/2-1”, “__NODEST=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct: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 [110@from-did-direct:13] Set(“Zap/2-1”, “RecordMethod=Group”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:14] Macro(“Zap/2-1”, “record-enable|110-1001|Group”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-record-enable: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 [110@from-did-direct:15] Set(“Zap/2-1”, “RingGroupMethod=ringall”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:16] Set(“Zap/2-1”, “_FMGRP=110”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:17] GotoIf(“Zap/2-1”, “0?doconfirm”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:18] Macro(“Zap/2-1”, “dial|20|tr|110-1001”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-dial: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 [110@from-did-direct: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 [110@from-did-direct:21] Set(“Zap/2-1”, “RingGroupMethod=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:22] GotoIf(“Zap/2-1”, “0?nodest”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct:23] Set(“Zap/2-1”, “__NODEST=”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [110@from-did-direct: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 [110@from-did-direct: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 [vmu110@ext-local:1] Macro(“Zap/2-1”, “vm|110|NOANSWER”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-vm:1] Macro(“Zap/2-1”, “user-callerid|SKIPTTL”) in new stack
[Jul 19 02:15:39] VERBOSE[5386] logger.c: – Executing [s@macro-user-callerid: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 [vmu110@ext-local: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’

its hanging up because you dont have nvfaxdetect installed