-- Executing [408@calldist-16:3] Dial("SIP/502-09024040", "Local/408@!SIP&Local/102@!SIP|10|g") in new stack
    -- Called 408@!SIP
    -- Called 102@!SIP
    -- Executing [408@!SIP:1] Set("Local/408@!SIP-75fd,2", "CALLEDPEER=408") in new stack
    -- Executing [408@!SIP:2] Set("Local/408@!SIP-75fd,2", "_CALLCHANNEL=SIP/408") in new stack
    -- Executing [408@!SIP:3] Set("Local/408@!SIP-75fd,2", "GROUP(RING_EXT)=408") in new stack
    -- Executing [408@!SIP:4] Set("Local/408@!SIP-75fd,2", "_CONNGROUPDEST=") in new stack
    -- Executing [408@!SIP:5] GotoIf("Local/408@!SIP-75fd,2", "1?CCG") in new stack
    -- Goto (!SIP,408,7)
    -- Executing [408@!SIP:7] MacroIf("Local/408@!SIP-75fd,2", "0?conngroup|||0|0|1") in new stack
    -- Executing [408@!SIP:8] Gosub("Local/408@!SIP-75fd,2", "!SIP-sring|408|1") in new stack
    -- Executing [408@!SIP-sring:1] Set("Local/408@!SIP-75fd,2", "ARRAY(PEERAGENT|ORG)=,INT") in new stack
    -- Executing [408@!SIP-sring:2] GotoIf("Local/408@!SIP-75fd,2", "0?NEXT") in new stack
    -- Executing [408@!SIP-sring:3] GotoIf("Local/408@!SIP-75fd,2", "0?NEXT") in new stack
    -- Executing [408@!SIP-sring:4] GotoIf("Local/408@!SIP-75fd,2", "0?NEXT") in new stack
    -- Executing [408@!SIP-sring:5] Return("Local/408@!SIP-75fd,2", "") in new stack
    -- Executing [408@!SIP:9] Dial("Local/408@!SIP-75fd,2", "SIP/408|11|gM(!CONNECTEXT^408)") in new stack
    -- Called 408
    -- Executing [102@!SIP:1] Set("Local/102@!SIP-7cd9,2", "CALLEDPEER=102") in new stack
    -- Executing [102@!SIP:2] Set("Local/102@!SIP-7cd9,2", "_CALLCHANNEL=SIP/102") in new stack
    -- Executing [102@!SIP:3] Set("Local/102@!SIP-7cd9,2", "GROUP(RING_EXT)=408") in new stack
    -- Executing [102@!SIP:4] Set("Local/102@!SIP-7cd9,2", "_CONNGROUPDEST=") in new stack
    -- Executing [102@!SIP:5] GotoIf("Local/102@!SIP-7cd9,2", "1?CCG") in new stack
    -- Goto (!SIP,102,7)
    -- Executing [102@!SIP:7] MacroIf("Local/102@!SIP-7cd9,2", "0?conngroup|||0|0|1") in new stack
    -- Executing [102@!SIP:8] Gosub("Local/102@!SIP-7cd9,2", "!SIP-sring|102|1") in new stack
    -- Executing [102@!SIP-sring:1] Set("Local/102@!SIP-7cd9,2", "ARRAY(PEERAGENT|ORG)=,INT") in new stack
    -- Executing [102@!SIP-sring:2] GotoIf("Local/102@!SIP-7cd9,2", "0?NEXT") in new stack
    -- Executing [102@!SIP-sring:3] GotoIf("Local/102@!SIP-7cd9,2", "0?NEXT") in new stack
    -- Executing [102@!SIP-sring:4] GotoIf("Local/102@!SIP-7cd9,2", "0?NEXT") in new stack
    -- Executing [102@!SIP-sring:5] Return("Local/102@!SIP-7cd9,2", "") in new stack
    -- Executing [102@!SIP:9] Dial("Local/102@!SIP-7cd9,2", "SIP/102|11|gM(!CONNECTEXT^408)") in new stack
    -- Called 102
Reliably Transmitting (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK067b6cea;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 106 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="4" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
 Extension Changed 408 new state Ringing for Notify User 406
    -- SIP/102-0904dec8 is ringing
    -- Local/102@!SIP-7cd9,1 is ringing
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK067b6cea;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 106 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
SIP Response message for INCOMING dialog NOTIFY arrived
    -- SIP/408-09039420 is ringing
    -- Local/408@!SIP-75fd,1 is ringing
    -- SIP/408-09039420 is ringing
    -- SIP/408-09039420 is ringing
Reliably Transmitting (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="5" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
 Extension Changed 408 new state InUse&Ringing for Notify User 406
    -- SIP/408-09039420 answered Local/408@!SIP-75fd,2
    -- Executing [s@macro-!CONNECTEXT:1] GotoIf("SIP/408-09039420", "0?END") in new stack
    -- Executing [s@macro-!CONNECTEXT:2] GotoIf("SIP/408-09039420", "1?SKIP") in new stack
    -- Goto (macro-!CONNECTEXT,s,5)
    -- Executing [s@macro-!CONNECTEXT:5] Set("SIP/408-09039420", "GROUP(DEST_EXT)=408") in new stack
    -- Executing [s@macro-!CONNECTEXT:6] Set("SIP/408-09039420", "CONNGROUPDEST=") in new stack
    -- Executing [s@macro-!CONNECTEXT:7] GotoIf("SIP/408-09039420", "1?SETLAST") in new stack
    -- Goto (macro-!CONNECTEXT,s,9)
    -- Executing [s@macro-!CONNECTEXT:9] GotoIf("SIP/408-09039420", "1?END") in new stack
    -- Goto (macro-!CONNECTEXT,s,11)
    -- Executing [s@macro-!CONNECTEXT:11] NoOp("SIP/408-09039420", "Call 1202226390.12 on channel SIP/408-09039420 to SIP/408 was answered.") in new stack
    -- Local/408@!SIP-75fd,1 stopped sounds
    -- Local/408@!SIP-75fd,1 answered SIP/502-09024040
  == Spawn extension (!SIP, 102, 9) exited non-zero on 'Local/102@!SIP-7cd9,2'
    -- Executing [h@!SIP:1] ExecIf("Local/102@!SIP-7cd9,2", "0|Hangup") in new stack
    -- Executing [h@!SIP:2] GosubIf("Local/102@!SIP-7cd9,2", "1?s|CDR") in new stack
    -- Executing [s@!SIP:2] Set("Local/102@!SIP-7cd9,2", "RINGINGTIME=3.163156") in new stack
    -- Executing [s@!SIP:3] Set("Local/102@!SIP-7cd9,2", "CALLINGEXT2=502") in new stack
    -- Executing [s@!SIP:4] Set("Local/102@!SIP-7cd9,2", "TRUNKID2=NULL") in new stack
    -- Executing [s@!SIP:5] Return("Local/102@!SIP-7cd9,2", "") in new stack
    -- Executing [h@!SIP:3] GotoIf("Local/102@!SIP-7cd9,2", "1?!SIP-evaluate|s|CANCEL") in new stack
    -- Goto (!SIP-evaluate,s,6)
    -- Executing [s@!SIP-evaluate:6] GotoIf("Local/102@!SIP-7cd9,2", "0?NOANSWER") in new stack
    -- Executing [s@!SIP-evaluate:7] GotoIf("Local/102@!SIP-7cd9,2", "0?PICKUPALT") in new stack
    -- Executing [s@!SIP-evaluate:8] NoOp("Local/102@!SIP-7cd9,2", ".... Call 1202226390 on channel Local/102@!SIP-7cd9,2 to SIP/102 Cancelled by the Calling Party ....") in new stack
    -- Executing [s@!SIP-evaluate:9] ExecIf("Local/102@!SIP-7cd9,2", "1|Set|ODBC_CDR()=1202226390,NULL,1202226390.439346,1202226393.663508,'502','408','SIP/502-09024040','SIP/102-0904dec8','user-01','user-08','CANCELLED',3.163156,0,'','"Handset Theo" <502>','phone','','16'") in new stack
Reliably Transmitting (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0543bbee;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 108 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 205

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="6" state="full" entity="sip:408@pbx.example.net">
<dialog id="408">
<state>confirmed</state>
</dialog>
</dialog-info>

---
 Extension Changed 408 new state InUse for Notify User 406
    -- Executing [s@!SIP-evaluate:10] Hangup("Local/102@!SIP-7cd9,2", "") in new stack
  == Spawn extension (!SIP-evaluate, s, 10) exited non-zero on 'Local/102@!SIP-7cd9,2'
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0543bbee;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 108 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
SIP Response message for INCOMING dialog NOTIFY arrived
    -- Native bridging SIP/502-09024040 and SIP/408-09039420
  == Spawn extension (!SIP, 408, 9) exited non-zero on 'Local/408@!SIP-75fd,2'
    -- Executing [h@!SIP:1] ExecIf("Local/408@!SIP-75fd,2", "0|Hangup") in new stack
    -- Executing [h@!SIP:2] GosubIf("Local/408@!SIP-75fd,2", "1?s|CDR") in new stack
    -- Executing [s@!SIP:2] Set("Local/408@!SIP-75fd,2", "RINGINGTIME=3.249930") in new stack
    -- Executing [s@!SIP:3] Set("Local/408@!SIP-75fd,2", "CALLINGEXT2=502") in new stack
    -- Executing [s@!SIP:4] Set("Local/408@!SIP-75fd,2", "TRUNKID2=NULL") in new stack
    -- Executing [s@!SIP:5] Return("Local/408@!SIP-75fd,2", "") in new stack
    -- Executing [h@!SIP:3] GotoIf("Local/408@!SIP-75fd,2", "0?!SIP-evaluate|s|ANSWER") in new stack
    -- Executing [h@!SIP:4] ExecIf("Local/408@!SIP-75fd,2", "1|Hangup") in new stack
  == Spawn extension (!SIP, h, 4) exited non-zero on 'Local/408@!SIP-75fd,2'
Retransmitting #1 (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="5" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
Retransmitting #2 (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="5" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
Retransmitting #3 (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="5" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
Retransmitting #4 (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 223

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="5" state="full" entity="sip:408@pbx.example.net">
<dialog id="408" direction="recipient">
<state>early</state>
</dialog>
</dialog-info>

---
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK4d277ca3;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 107 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
    -- Executing [408@calldist-16:4] Macro("SIP/502-09024040", "endcall|ANSWER|N|0") in new stack
    -- Executing [s@macro-endcall:1] ExecIf("SIP/502-09024040", "0|Set|ARRAY(ARG1|ARG2|ARG3)=,N,") in new stack
    -- Executing [s@macro-endcall:2] NoOp("SIP/502-09024040", "BT: xx  BP: xSIP/408-09039420x") in new stack
    -- Executing [s@macro-endcall:3] Goto("SIP/502-09024040", "ANSWER") in new stack
    -- Goto (macro-endcall,s,4)
    -- Executing [s@macro-endcall:4] GotoIf("SIP/502-09024040", "0?ANSWER-EXIT") in new stack
    -- Executing [s@macro-endcall:5] GotoIf("SIP/502-09024040", "0?ANSWER-EXIT") in new stack
    -- Executing [s@macro-endcall:6] GotoIf("SIP/502-09024040", "0?ANSWER-CALLING:ANSWER-CALLED") in new stack
    -- Goto (macro-endcall,s,8)
    -- Executing [s@macro-endcall:8] NoOp("SIP/502-09024040", ".... Called Party Hungup .... ") in new stack
    -- Executing [s@macro-endcall:9] GosubIf("SIP/502-09024040", "1?ANSWER-CDR") in new stack
Reliably Transmitting (no NAT) to 192.168.161.243:5060:
NOTIFY sip:406@192.168.161.243:5060;line=u8pkfgw2 SIP/2.0
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK7188d3a2;rport
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Contact: <sip:408@192.168.161.100>
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 109 NOTIFY
User-Agent: atCOM PBX
Max-Forwards: 70
Event: dialog
Content-Type: application/dialog-info+xml
Subscription-State: active
Content-Length: 206

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="7" state="full" entity="sip:408@pbx.example.net">
<dialog id="408">
<state>terminated</state>
</dialog>
</dialog-info>

---
 Extension Changed 408 new state Idle for Notify User 406
    -- Executing [s@macro-endcall:16] ExecIf("SIP/502-09024040", "0|Set|CALLEDEXT=408") in new stack
    -- Executing [s@macro-endcall:17] Set("SIP/502-09024040", "RINGTIMECORR=0") in new stack
    -- Executing [s@macro-endcall:18] Set("SIP/502-09024040", "CONTEXTDEST=user-08") in new stack
    -- Executing [s@macro-endcall:19] Set("SIP/502-09024040", "STARTTIME=1202226390.401291") in new stack
    -- Executing [s@macro-endcall:20] Set("SIP/502-09024040", "RINGINGTIME=3.259351") in new stack
    -- Executing [s@macro-endcall:21] Set("SIP/502-09024040", "DURATION=9.277970") in new stack
    -- Executing [s@macro-endcall:22] Set("SIP/502-09024040", "DISPOSITION=ANSWERED1") in new stack
    -- Executing [s@macro-endcall:23] Set("SIP/502-09024040", "CALLINGEXT2=502") in new stack
    -- Executing [s@macro-endcall:24] Set("SIP/502-09024040", "TRUNKID2=NULL") in new stack
    -- Executing [s@macro-endcall:25] Set("SIP/502-09024040", "ODBC_CDR()=1202226390,NULL,1202226390.401291,1202226402.938928,'502','408','SIP/502-09024040','SIP/408-09039420','user-01','user-08','ANSWERED1',3.259351,9.277970,'','"Handset Theo" <502>','phone','','16'") in new stack
    -- Executing [s@macro-endcall:26] ResetCDR("SIP/502-09024040", "w") in new stack
    -- Executing [s@macro-endcall:27] Return("SIP/502-09024040", "") in new stack
    -- Executing [s@macro-endcall:10] ExecIf("SIP/502-09024040", "0|MacroExit|") in new stack
    -- Executing [s@macro-endcall:11] Hangup("SIP/502-09024040", "") in new stack
  == Spawn extension (macro-endcall, s, 11) exited non-zero on 'SIP/502-09024040' in macro 'endcall'
  == Spawn extension (macro-endcall, s, 11) exited non-zero on 'SIP/502-09024040'
    -- Executing [h@macro-endcall:1] ExecIf("SIP/502-09024040", "0|Goto|s|VOICEMAIL-CDR") in new stack
    -- Executing [h@macro-endcall:2] NoOp("SIP/502-09024040", ".... End of call .... 1202226390") in new stack
pbx*CLI>
<--- SIP read from 192.168.161.243:5060 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK7188d3a2;rport=5060
From: <sip:408@pbx.example.net;user=phone>;tag=as6a83460e
To: <sip:406@pbx.example.net>;tag=dbag2a82z5
Call-ID: 3c26701788b8-rc29mso7ycw8@snom320-0004132429F1
CSeq: 109 NOTIFY
Content-Length: 0