Hi,
This is happening frequently, to specific tellephone numbers. We can reproduce this. I have NO idea what is causing this. I suspect that this is calls to other PBX systems via the PSTN that also runs asterisk.
- We make a OUTBOUND call via the PSTN (PRI Trunk) to a remote System
- Remote Answers, and converse
- Remote sends DTMF on their site to transfer call
- Our * system initiates on hold with our on hold music
- ZAP channel drops, followed shortly after by the SIP channel.
DTMF Debugging has been enabled too, below a trace for the latest call where this happened. Does anyone have any idea why this is happening, and what I can look at? I already tried all posibilities for priindication as well as relaxeddtmf=yes in zapata.conf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [0117709800@from-internal:1] Macro(“SIP/8647-b6f96650”, “user-callerid|SKIPTTL|”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/8647-b6f96650”, “AMPUSER=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/8647-b6f96650”, “0?report”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/8647-b6f96650”, “1|Set|REALCALLERIDNUM=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/8647-b6f96650”, “AMPUSER=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/8647-b6f96650”, “AMPUSERCIDNAME=Ntombi Njongo”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/8647-b6f96650”, “0?report”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/8647-b6f96650”, “AMPUSERCID=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/8647-b6f96650”, “CALLERID(all)=“Ntombi Njongo” <8647>”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:9] Set(“SIP/8647-b6f96650”, “REALCALLERIDNUM=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/8647-b6f96650”, “1?continue”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Goto (macro-user-callerid,s,19)
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-user-callerid:19] NoOp(“SIP/8647-b6f96650”, “Using CallerID “Ntombi Njongo” <8647>”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Noop
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [0117709800@from-internal:2] Set(“SIP/8647-b6f96650”, “_NODEST=”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [0117709800@from-internal:3] Macro(“SIP/8647-b6f96650”, “record-enable|8647|OUT|”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/8647-b6f96650”, “1?check”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Goto (macro-record-enable,s,4)
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/8647-b6f96650”, “recordingcheck|20090313-133037|1236943837.1282”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Mar 13 13:30:37] VERBOSE[28294] logger.c: recordingcheck|20090313-133037|1236943837.1282: Outbound recording not enabled
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – AGI Script recordingcheck completed, returning 0
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: AGI
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-record-enable:5] MacroExit(“SIP/8647-b6f96650”, “”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [0117709800@from-internal:4] Macro(“SIP/8647-b6f96650”, “dialout-trunk|3|0117709800||”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/8647-b6f96650”, “DIAL_TRUNK=3”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] DEBUG[28294] func_db.c: DB: AMPUSER/8647/pinless not found in database.
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/8647-b6f96650”, “0?sub-pincheck|s|1”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GosubIf
[Mar 13 13:30:37] DEBUG[28294] func_db.c: DB: AMPUSER/8647/pinless not found in database.
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/8647-b6f96650”, “0?disabletrunk|1”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/8647-b6f96650”, “DIAL_NUMBER=0117709800”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/8647-b6f96650”, “DIAL_TRUNK_OPTIONS=tT”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/8647-b6f96650”, “OUTBOUND_GROUP=OUT_3”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/8647-b6f96650”, “1?nomax”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Goto (macro-dialout-trunk,s,9)
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/8647-b6f96650”, “0?skipoutcid”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/8647-b6f96650”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/8647-b6f96650”, “outbound-callerid|3”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/8647-b6f96650”, “0|SetCallerPres|”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/8647-b6f96650”, “0|Set|REALCALLERIDNUM=8647”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/8647-b6f96650”, “1?normcid”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Goto (macro-outbound-callerid,s,6)
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/8647-b6f96650”, “USEROUTCID=0218188600”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] DEBUG[28294] func_db.c: DB: DEVICE/8647/emergency_cid not found in database.
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/8647-b6f96650”, “EMERGENCYCID=”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/8647-b6f96650”, “TRUNKOUTCID=”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/8647-b6f96650”, “1?trunkcid”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Goto (macro-outbound-callerid,s,12)
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/8647-b6f96650”, “0|Set|CALLERID(all)=”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:13] GotoIf(“SIP/8647-b6f96650”, “0?exit”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:14] Set(“SIP/8647-b6f96650”, “CALLERID(all)=0218188600”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/8647-b6f96650”, “0|SetCallerPres|prohib_passed_screen”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Macro
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:12] ExecIf(“SIP/8647-b6f96650”, “0|AGI|fixlocalprefix”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/8647-b6f96650”, “OUTNUM=0117709800”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/8647-b6f96650”, “custom=ZAP/g1”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Set
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/8647-b6f96650”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)T”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: ExecIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/8647-b6f96650”, “dialout-trunk-predial-hook|”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/8647-b6f96650”, “”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: Macro
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/8647-b6f96650”, “0?bypass|1”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/8647-b6f96650”, “0?customtrunk”) in new stack
[Mar 13 13:30:37] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/8647-b6f96650”, “ZAP/g1/0117709800|300|T”) in new stack
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Requested transfer capability: 0x00 - SPEECH
[Mar 13 13:30:37] VERBOSE[28294] logger.c: – Called g1/0117709800
[Mar 13 13:30:38] VERBOSE[28294] logger.c: – Zap/1-1 is proceeding passing it to SIP/8647-b6f96650
[Mar 13 13:30:38] VERBOSE[28294] logger.c: – Zap/1-1 is making progress passing it to SIP/8647-b6f96650
[Mar 13 13:30:39] VERBOSE[28294] logger.c: – Zap/1-1 is ringing
[Mar 13 13:30:43] VERBOSE[28294] logger.c: – Zap/1-1 answered SIP/8647-b6f96650
[Mar 13 13:30:50] VERBOSE[28294] logger.c: – Started music on hold, class ‘default’, on SIP/8647-b6f96650
[Mar 13 13:31:01] DEBUG[28294] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
[Mar 13 13:31:01] DEBUG[28294] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
[Mar 13 13:31:01] DEBUG[28294] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Hungup ‘Zap/1-1’
[Mar 13 13:31:01] VERBOSE[28294] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/8647-b6f96650’ in macro ‘dialout-trunk’
[Mar 13 13:31:01] VERBOSE[28294] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/8647-b6f96650’
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/8647-b6f96650”, “hangupcall|”) in new stack
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/8647-b6f96650”, “w”) in new stack
[Mar 13 13:31:01] DEBUG[28294] app_macro.c: Executed application: ResetCDR
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/8647-b6f96650”, “”) in new stack
[Mar 13 13:31:01] DEBUG[28294] app_macro.c: Executed application: NoCDR
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/8647-b6f96650”, “1?skiprg”) in new stack
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Goto (macro-hangupcall,s,6)
[Mar 13 13:31:01] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/8647-b6f96650”, “1?skipblkvm”) in new stack
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Goto (macro-hangupcall,s,9)
[Mar 13 13:31:01] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/8647-b6f96650”, “1?theend”) in new stack
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Goto (macro-hangupcall,s,11)
[Mar 13 13:31:01] DEBUG[28294] app_macro.c: Executed application: GotoIf
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/8647-b6f96650”, “”) in new stack
[Mar 13 13:31:01] VERBOSE[28294] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/8647-b6f96650’ in macro ‘hangupcall’
[Mar 13 13:31:01] VERBOSE[28294] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/8647-b6f96650’
[Mar 13 13:31:01] VERBOSE[28294] logger.c: – Stopped music on hold on SIP/8647-b6f96650