Here goes the log.
101 called 180, heard playback(numbers) and was bridged with 180. They are talking, call waiting is disabled.
103 called 180, heard playback(numbers) and got hungup. It makes him very upset(
Asterisk 1.8.7.0 built by palosanto @ rpmbuild64-2.elastix.palosanto.com on a x86_64
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
-- Executing [180@from-internal:1] GotoIf("SIP/101-00000105", "0?ext-local,180,1") in new stack
-- Executing [180@from-internal:2] Macro("SIP/101-00000105", "user-callerid,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/101-00000105", "AMPUSER=101") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/101-00000105", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/101-00000105", "1?Set(REALCALLERIDNUM=101)") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/101-00000105", "AMPUSER=101") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/101-00000105", "AMPUSERCIDNAME=root") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/101-00000105", "0?report") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/101-00000105", "AMPUSERCID=101") in new stack
-- Executing [s@macro-user-callerid:8] Set("SIP/101-00000105", "CALLERID(all)="root" <101>") in new stack
-- Executing [s@macro-user-callerid:9] ExecIf("SIP/101-00000105", "0?Set(CHANNEL(language)=)") in new stack
-- Executing [s@macro-user-callerid:10] GotoIf("SIP/101-00000105", "0?continue") in new stack
-- Executing [s@macro-user-callerid:11] Set("SIP/101-00000105", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("SIP/101-00000105", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] Set("SIP/101-00000105", "CALLERID(number)=101") in new stack
-- Executing [s@macro-user-callerid:20] Set("SIP/101-00000105", "CALLERID(name)=root") in new stack
-- Executing [s@macro-user-callerid:21] NoOp("SIP/101-00000105", "Using CallerID "root" <101>") in new stack
-- Executing [180@from-internal:3] Set("SIP/101-00000105", "__EXTTOCALL=180") in new stack
-- Executing [180@from-internal:4] GotoIf("SIP/101-00000105", "1?skipdb") in new stack
-- Goto (from-internal,180,6)
-- Executing [180@from-internal:6] Set("SIP/101-00000105", "__NODEST=") in new stack
-- Executing [180@from-internal:7] Set("SIP/101-00000105", "__BLKVM_OVERRIDE=BLKVM/180/SIP/101-00000105") in new stack
-- Executing [180@from-internal:8] Set("SIP/101-00000105", "__BLKVM_BASE=180") in new stack
-- Executing [180@from-internal:9] Set("SIP/101-00000105", "DB(BLKVM/180/SIP/101-00000105)=TRUE") in new stack
-- Executing [180@from-internal:10] Set("SIP/101-00000105", "RRNODEST=") in new stack
-- Executing [180@from-internal:11] Set("SIP/101-00000105", "__NODEST=180") in new stack
-- Executing [180@from-internal:12] GosubIf("SIP/101-00000105", "0?sub-fmsetcid,s,1") in new stack
-- Executing [180@from-internal:13] Set("SIP/101-00000105", "RecordMethod=Group") in new stack
-- Executing [180@from-internal:14] Macro("SIP/101-00000105", "record-enable,180-180,Group") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("SIP/101-00000105", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] ExecIf("SIP/101-00000105", "0?MacroExit()") in new stack
-- Executing [s@macro-record-enable:5] GotoIf("SIP/101-00000105", "1?Group:OUT") in new stack
-- Goto (macro-record-enable,s,6)
-- Executing [s@macro-record-enable:6] Set("SIP/101-00000105", "LOOPCNT=2") in new stack
-- Executing [s@macro-record-enable:7] Set("SIP/101-00000105", "ITER=1") in new stack
-- Executing [s@macro-record-enable:8] GotoIf("SIP/101-00000105", "1?continue") in new stack
-- Goto (macro-record-enable,s,13)
-- Executing [s@macro-record-enable:13] Set("SIP/101-00000105", "ITER=2") in new stack
-- Executing [s@macro-record-enable:14] GotoIf("SIP/101-00000105", "1?begin") in new stack
-- Goto (macro-record-enable,s,8)
-- Executing [s@macro-record-enable:8] GotoIf("SIP/101-00000105", "1?continue") in new stack
-- Goto (macro-record-enable,s,13)
-- Executing [s@macro-record-enable:13] Set("SIP/101-00000105", "ITER=3") in new stack
-- Executing [s@macro-record-enable:14] GotoIf("SIP/101-00000105", "0?begin") in new stack
-- Executing [s@macro-record-enable:15] GotoIf("SIP/101-00000105", "0?IN") in new stack
-- Executing [s@macro-record-enable:16] ExecIf("SIP/101-00000105", "1?MacroExit()") in new stack
-- Executing [180@from-internal:15] Set("SIP/101-00000105", "RingGroupMethod=ringallv2") in new stack
-- Executing [180@from-internal:16] Set("SIP/101-00000105", "_FMGRP=180") in new stack
-- Executing [180@from-internal:17] GotoIf("SIP/101-00000105", "0?DIALGRP") in new stack
-- Executing [180@from-internal:18] Answer("SIP/101-00000105", "") in new stack
-- Executing [180@from-internal:19] Wait("SIP/101-00000105", "1") in new stack
-- Executing [180@from-internal:20] Playback("SIP/101-00000105", "custom/numbers") in new stack
-- <SIP/101-00000105> Playing 'custom/numbers.slin' (language 'en')
-- Executing [180@from-internal:21] GotoIf("SIP/101-00000105", "0?doconfirm") in new stack
-- Executing [180@from-internal:22] Macro("SIP/101-00000105", "dial,20,tTr,180") in new stack
-- Executing [s@macro-dial:1] GotoIf("SIP/101-00000105", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [s@macro-dial:3] AGI("SIP/101-00000105", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is 'root' number is '101'
> dialparties.agi: USE_CONFIRMATION: 'FALSE'
> dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is 'ringallv2'
-- dialparties.agi: Added extension 180 to extension map
> dialparties.agi: got fmgrp_prering: 2, fmgrp_grptime: 20
> dialparties.agi: fmgrp_totalprering: 22
> dialparties.agi: found extension in pre-ring and array
> dialparties.agi: ringallv2 ring times: REALPRERING: 22, PRERING: 2
-- dialparties.agi: Extension 180 cf is disabled
-- dialparties.agi: Extension 180 do not disturb is disabled
> dialparties.agi: extnum 180 has: cw: 0; hascfb: 0 [] hascfu: 0 []
dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
dialparties.agi: Extension 180 has ExtensionState: 0
-- dialparties.agi: Checking CW and CFB status for extension 180
-- dialparties.agi: dbset CALLTRACE/180 to 101
-- dialparties.agi: Filtered ARG3: 180
> dialparties.agi: NODEST: 180 adding M(auto-blkvm) to dialopts: tTrM(auto-blkvm)
> dialparties.agi: NODEST: 180 blkvm enabled macro already in dialopts: tTrM(auto-blkvm)
-- <SIP/101-00000105>AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:7] Dial("SIP/101-00000105", "SIP/180,22,tTrM(auto-blkvm)") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
-- Called SIP/180
-- SIP/180-00000106 is ringing
-- SIP/180-00000106 answered SIP/101-00000105
-- Executing [s@macro-auto-blkvm:1] Set("SIP/180-00000106", "__MACRO_RESULT=") in new stack
-- Executing [s@macro-auto-blkvm:2] NoOp("SIP/180-00000106", "Deleting: BLKVM/180/SIP/101-00000105 TRUE") in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
-- Executing [180@from-internal:1] GotoIf("SIP/103-00000107", "0?ext-local,180,1") in new stack
-- Executing [180@from-internal:2] Macro("SIP/103-00000107", "user-callerid,") in new stack
-- Executing [s@macro-user-callerid:1] Set("SIP/103-00000107", "AMPUSER=103") in new stack
-- Executing [s@macro-user-callerid:2] GotoIf("SIP/103-00000107", "0?report") in new stack
-- Executing [s@macro-user-callerid:3] ExecIf("SIP/103-00000107", "1?Set(REALCALLERIDNUM=103)") in new stack
-- Executing [s@macro-user-callerid:4] Set("SIP/103-00000107", "AMPUSER=103") in new stack
-- Executing [s@macro-user-callerid:5] Set("SIP/103-00000107", "AMPUSERCIDNAME=ekorolev") in new stack
-- Executing [s@macro-user-callerid:6] GotoIf("SIP/103-00000107", "0?report") in new stack
-- Executing [s@macro-user-callerid:7] Set("SIP/103-00000107", "AMPUSERCID=103") in new stack
-- Executing [s@macro-user-callerid:8] Set("SIP/103-00000107", "CALLERID(all)="ekorolev" <103>") in new stack
-- Executing [s@macro-user-callerid:9] ExecIf("SIP/103-00000107", "0?Set(CHANNEL(language)=)") in new stack
-- Executing [s@macro-user-callerid:10] GotoIf("SIP/103-00000107", "0?continue") in new stack
-- Executing [s@macro-user-callerid:11] Set("SIP/103-00000107", "__TTL=64") in new stack
-- Executing [s@macro-user-callerid:12] GotoIf("SIP/103-00000107", "1?continue") in new stack
-- Goto (macro-user-callerid,s,19)
-- Executing [s@macro-user-callerid:19] Set("SIP/103-00000107", "CALLERID(number)=103") in new stack
-- Executing [s@macro-user-callerid:20] Set("SIP/103-00000107", "CALLERID(name)=ekorolev") in new stack
-- Executing [s@macro-user-callerid:21] NoOp("SIP/103-00000107", "Using CallerID "ekorolev" <103>") in new stack
-- Executing [180@from-internal:3] Set("SIP/103-00000107", "__EXTTOCALL=180") in new stack
-- Executing [180@from-internal:4] GotoIf("SIP/103-00000107", "1?skipdb") in new stack
-- Goto (from-internal,180,6)
-- Executing [180@from-internal:6] Set("SIP/103-00000107", "__NODEST=") in new stack
-- Executing [180@from-internal:7] Set("SIP/103-00000107", "__BLKVM_OVERRIDE=BLKVM/180/SIP/103-00000107") in new stack
-- Executing [180@from-internal:8] Set("SIP/103-00000107", "__BLKVM_BASE=180") in new stack
-- Executing [180@from-internal:9] Set("SIP/103-00000107", "DB(BLKVM/180/SIP/103-00000107)=TRUE") in new stack
-- Executing [180@from-internal:10] Set("SIP/103-00000107", "RRNODEST=") in new stack
-- Executing [180@from-internal:11] Set("SIP/103-00000107", "__NODEST=180") in new stack
-- Executing [180@from-internal:12] GosubIf("SIP/103-00000107", "0?sub-fmsetcid,s,1") in new stack
-- Executing [180@from-internal:13] Set("SIP/103-00000107", "RecordMethod=Group") in new stack
-- Executing [180@from-internal:14] Macro("SIP/103-00000107", "record-enable,180-180,Group") in new stack
-- Executing [s@macro-record-enable:1] GotoIf("SIP/103-00000107", "1?check") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing [s@macro-record-enable:4] ExecIf("SIP/103-00000107", "0?MacroExit()") in new stack
-- Executing [s@macro-record-enable:5] GotoIf("SIP/103-00000107", "1?Group:OUT") in new stack
-- Goto (macro-record-enable,s,6)
-- Executing [s@macro-record-enable:6] Set("SIP/103-00000107", "LOOPCNT=2") in new stack
-- Executing [s@macro-record-enable:7] Set("SIP/103-00000107", "ITER=1") in new stack
-- Executing [s@macro-record-enable:8] GotoIf("SIP/103-00000107", "1?continue") in new stack
-- Goto (macro-record-enable,s,13)
-- Executing [s@macro-record-enable:13] Set("SIP/103-00000107", "ITER=2") in new stack
-- Executing [s@macro-record-enable:14] GotoIf("SIP/103-00000107", "1?begin") in new stack
-- Goto (macro-record-enable,s,8)
-- Executing [s@macro-record-enable:8] GotoIf("SIP/103-00000107", "1?continue") in new stack
-- Goto (macro-record-enable,s,13)
-- Executing [s@macro-record-enable:13] Set("SIP/103-00000107", "ITER=3") in new stack
-- Executing [s@macro-record-enable:14] GotoIf("SIP/103-00000107", "0?begin") in new stack
-- Executing [s@macro-record-enable:15] GotoIf("SIP/103-00000107", "0?IN") in new stack
-- Executing [s@macro-record-enable:16] ExecIf("SIP/103-00000107", "1?MacroExit()") in new stack
-- Executing [180@from-internal:15] Set("SIP/103-00000107", "RingGroupMethod=ringallv2") in new stack
-- Executing [180@from-internal:16] Set("SIP/103-00000107", "_FMGRP=180") in new stack
-- Executing [180@from-internal:17] GotoIf("SIP/103-00000107", "0?DIALGRP") in new stack
-- Executing [180@from-internal:18] Answer("SIP/103-00000107", "") in new stack
-- Executing [180@from-internal:19] Wait("SIP/103-00000107", "1") in new stack
-- Executing [180@from-internal:20] Playback("SIP/103-00000107", "custom/numbers") in new stack
-- <SIP/103-00000107> Playing 'custom/numbers.slin' (language 'en')
-- Executing [180@from-internal:21] GotoIf("SIP/103-00000107", "0?doconfirm") in new stack
-- Executing [180@from-internal:22] Macro("SIP/103-00000107", "dial,20,tTr,180") in new stack
-- Executing [s@macro-dial:1] GotoIf("SIP/103-00000107", "1?dial") in new stack
-- Goto (macro-dial,s,3)
-- Executing [s@macro-dial:3] AGI("SIP/103-00000107", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Caller ID name is 'ekorolev' number is '103'
> dialparties.agi: USE_CONFIRMATION: 'FALSE'
> dialparties.agi: RINGGROUP_INDEX: ''
dialparties.agi: Methodology of ring is 'ringallv2'
-- dialparties.agi: Added extension 180 to extension map
> dialparties.agi: got fmgrp_prering: 2, fmgrp_grptime: 20
> dialparties.agi: fmgrp_totalprering: 22
> dialparties.agi: found extension in pre-ring and array
> dialparties.agi: ringallv2 ring times: REALPRERING: 22, PRERING: 2
-- dialparties.agi: Extension 180 cf is disabled
-- dialparties.agi: Extension 180 do not disturb is disabled
> dialparties.agi: extnum 180 has: cw: 0; hascfb: 0 [] hascfu: 0 []
dialparties.agi: EXTENSION_STATE: 1 (INUSE)
dialparties.agi: Extension 180 has ExtensionState: 1
-- dialparties.agi: Checking CW and CFB status for extension 180
dialparties.agi: Extension 180 is not available to be called
dialparties.agi: Extension 180 has call waiting disabled
-- dialparties.agi: Filtered ARG3:
> dialparties.agi: NODEST: 180 adding M(auto-blkvm) to dialopts: tTrM(auto-blkvm)
> dialparties.agi: NODEST: 180 blkvm enabled macro already in dialopts: tTrM(auto-blkvm)
-- <SIP/103-00000107>AGI Script dialparties.agi completed, returning 0
-- Executing [s@macro-dial:4] NoOp("SIP/103-00000107", "Returned from dialparties with no extensions to call and DIALSTATUS: BUSY") in new stack
-- Executing [180@from-internal:23] Goto("SIP/103-00000107", "nextstep") in new stack
-- Goto (from-internal,180,25)
-- Executing [180@from-internal:25] Set("SIP/103-00000107", "RingGroupMethod=") in new stack
-- Executing [180@from-internal:26] GotoIf("SIP/103-00000107", "0?nodest") in new stack
-- Executing [180@from-internal:27] Set("SIP/103-00000107", "__NODEST=") in new stack
-- Executing [180@from-internal:28] NoOp("SIP/103-00000107", "Deleting: BLKVM/180/SIP/103-00000107 TRUE") in new stack
-- Executing [180@from-internal:29] Goto("SIP/103-00000107", "app-blackhole,hangup,1") in new stack
-- Goto (app-blackhole,hangup,1)
-- Executing [hangup@app-blackhole:1] NoOp("SIP/103-00000107", "Blackhole Dest: Hangup") in new stack
-- Executing [hangup@app-blackhole:2] Hangup("SIP/103-00000107", "") in new stack
== Spawn extension (app-blackhole, hangup, 2) exited non-zero on 'SIP/103-00000107'