Hello Asterisk Gurus, I have a very strange problem…
From time to time, some calls (aparrently random calls) are finished normal, but get’s mutted, on both sides. This happens both for incomming and outgoing calls.
If you keep trying tough, sometimes it may work…now this is very odd and I can’t seem to find the reason, here’s a sample output from the Asterisk logs (in this log, internal user 10002 is trying to call 30896690, it finishes the call and the outer phone answers, however nobody can hear nobody):
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [030896690@custom-DDI:1] Macro("SIP/10002-b7e57298", "user-callerid|SKIPTTL|") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/10002-b7e57298", "AMPUSER=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/10002-b7e57298", "0?report") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/10002-b7e57298", "1|Set|REALCALLERIDNUM=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/10002-b7e57298", "AMPUSER=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/10002-b7e57298", "AMPUSERCIDNAME=Ana Diva") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/10002-b7e57298", "0?report") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/10002-b7e57298", "AMPUSERCID=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/10002-b7e57298", "CALLERID(all)="Ana Diva" <10002>") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:9] ExecIf("SIP/10002-b7e57298", "0|Set|CHANNEL(language)=") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/10002-b7e57298", "1?continue") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-user-callerid,s,19)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:19] Set("SIP/10002-b7e57298", "CALLERID(number)=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:20] Set("SIP/10002-b7e57298", "CALLERID(name)=Ana Diva") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-user-callerid:21] NoOp("SIP/10002-b7e57298", "Using CallerID "Ana Diva" <10002>") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Noop
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [030896690@custom-DDI:2] Set("SIP/10002-b7e57298", "_NODEST=") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [030896690@custom-DDI:3] Macro("SIP/10002-b7e57298", "record-enable|10002|OUT|") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/10002-b7e57298", "1?check") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-record-enable,s,4)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/10002-b7e57298", "recordingcheck|20111103-160742|1320343662.99899") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Nov 3 16:07:42] VERBOSE[16046] logger.c: recordingcheck|20111103-160742|1320343662.99899: Outbound recording not enabled
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- AGI Script recordingcheck completed, returning 0
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: AGI
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/10002-b7e57298", "") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [030896690@custom-DDI:4] Macro("SIP/10002-b7e57298", "dialout-trunk|1|30896690||") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/10002-b7e57298", "DIAL_TRUNK=1") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] DEBUG[16046] func_db.c: DB: AMPUSER/10002/pinless not found in database.
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/10002-b7e57298", "0?sub-pincheck|s|1") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GosubIf
[Nov 3 16:07:42] DEBUG[16046] func_db.c: DB: AMPUSER/10002/pinless not found in database.
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/10002-b7e57298", "0?disabletrunk|1") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/10002-b7e57298", "DIAL_NUMBER=30896690") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/10002-b7e57298", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/10002-b7e57298", "OUTBOUND_GROUP=OUT_1") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/10002-b7e57298", "0?nomax") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/10002-b7e57298", "0?chanfull") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/10002-b7e57298", "0?skipoutcid") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/10002-b7e57298", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/10002-b7e57298", "outbound-callerid|1") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/10002-b7e57298", "0|SetCallerPres|") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/10002-b7e57298", "0|Set|REALCALLERIDNUM=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/10002-b7e57298", "1?normcid") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-outbound-callerid,s,6)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/10002-b7e57298", "USEROUTCID=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] DEBUG[16046] func_db.c: DB: DEVICE/10002/emergency_cid not found in database.
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/10002-b7e57298", "EMERGENCYCID=") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/10002-b7e57298", "TRUNKOUTCID=1140810000") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/10002-b7e57298", "1?trunkcid") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-outbound-callerid,s,12)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/10002-b7e57298", "1|Set|CALLERID(all)=1140810000") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Last app: Set|CALLERID(all)=1140810000
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/10002-b7e57298", "1|Set|CALLERID(all)=10002") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Last app: Set|CALLERID(all)=10002
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/10002-b7e57298", "0|SetCallerPres|prohib_passed_screen") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Macro
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/10002-b7e57298", "1|AGI|fixlocalprefix") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix
[Nov 3 16:07:42] VERBOSE[16046] logger.c: > fixlocalprefix: Using pattern 025+0|ZZNXXXXXXX
[Nov 3 16:07:42] VERBOSE[16046] logger.c: > fixlocalprefix: Using pattern 0025+00|ZZZXXXXXX.
[Nov 3 16:07:42] VERBOSE[16046] logger.c: > fixlocalprefix: Using pattern 025+ZZNXXXXXXX
[Nov 3 16:07:42] VERBOSE[16046] logger.c: > fixlocalprefix: Using pattern .
[Nov 3 16:07:42] VERBOSE[16046] logger.c: == fixlocalprefix: Dialpattern . matched. 30896690 -> 30896690
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- AGI Script fixlocalprefix completed, returning 0
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Last app: AGI|fixlocalprefix
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/10002-b7e57298", "OUTNUM=30896690") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/10002-b7e57298", "custom=AMP") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/10002-b7e57298", "0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)Tt") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: ExecIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/10002-b7e57298", "dialout-trunk-predial-hook|") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/10002-b7e57298", "") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Macro
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/10002-b7e57298", "0?bypass|1") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/10002-b7e57298", "1?customtrunk") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-dialout-trunk,s,21)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:21] Set("SIP/10002-b7e57298", "pre_num=AMP:Dgv/G6/") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:22] Set("SIP/10002-b7e57298", "the_num=OUTNUM") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:23] Set("SIP/10002-b7e57298", "post_num=") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:24] GotoIf("SIP/10002-b7e57298", "1?outnum:skipoutnum") in new stack
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Goto (macro-dialout-trunk,s,25)
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:25] Set("SIP/10002-b7e57298", "the_num=30896690") in new stack
[Nov 3 16:07:42] DEBUG[16046] app_macro.c: Executed application: Set
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Executing [s@macro-dialout-trunk:26] Dial("SIP/10002-b7e57298", "Dgv/G6/30896690|300|Tt") in new stack
[Nov 3 16:07:42] NOTICE[16046] chan_dgv.c: Asked to get a channel Dgv/G6/30896690 using format AST_FORMAT_ULAW:ffWaveULaw
[Nov 3 16:07:42] NOTICE[16046] chan_dgv.c: Group G6
[Nov 3 16:07:42] VERBOSE[16046] logger.c: -- Called G6/30896690
[Nov 3 16:07:51] VERBOSE[16046] logger.c: -- DGV/64 is ringing
[Nov 3 16:07:54] VERBOSE[16046] logger.c: -- DGV/64 answered SIP/10002-b7e57298
[Nov 3 16:08:07] NOTICE[16046] chan_dgv.c: Calling dg_HangUp on port 64
[Nov 3 16:08:07] VERBOSE[16046] logger.c: == Spawn extension (macro-dialout-trunk, s, 26) exited non-zero on 'SIP/10002-b7e57298' in macro 'dialout-trunk'
[Nov 3 16:08:07] VERBOSE[16046] logger.c: == Spawn extension (macro-dialout-trunk, s, 26) exited non-zero on 'SIP/10002-b7e57298'
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/10002-b7e57298", "hangupcall|") in new stack
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/10002-b7e57298", "1?skiprg") in new stack
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Goto (macro-hangupcall,s,4)
[Nov 3 16:08:07] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/10002-b7e57298", "1?skipblkvm") in new stack
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Goto (macro-hangupcall,s,7)
[Nov 3 16:08:07] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/10002-b7e57298", "1?theend") in new stack
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Goto (macro-hangupcall,s,9)
[Nov 3 16:08:07] DEBUG[16046] app_macro.c: Executed application: GotoIf
[Nov 3 16:08:07] VERBOSE[16046] logger.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/10002-b7e57298", "") in new stack
[Nov 3 16:08:07] VERBOSE[16046] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/10002-b7e57298' in macro 'hangupcall'
[Nov 3 16:08:07] VERBOSE[16046] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/10002-b7e57298'Thanks for the help.