From what I can see in the logs, the receiving end forwards to voicemail. It makes sense that at that point I would begin hearing the VM greeting. About 7 seconds later on the calling end I get a BYE from local - so it seems that the call is being terminated on the sending end right after the message completes and tone plays.
I have also tried changing from a tunnel connection to standard and no change.
Log from server where call originated:
10/06/2017 9:07:43 AM - Leg L:4968.1[Extn:3983] is terminated: Cause: BYE from local
10/06/2017 9:07:43 AM - [CM503008]: Call(C:4968): Call is terminated
10/06/2017 9:07:43 AM - Leg L:4968.2[Line:10002>>299] is terminated: Cause: BYE from 127.0.0.1:5080
10/06/2017 9:07:43 AM - Leg L:4968.1[Extn:3983] is terminated: Cause: BYE from local
10/06/2017 9:07:35 AM - [CM503007]: Call(C:4968): Extn:3983 has joined, contact <sip:
[email protected]:5060>
10/06/2017 9:07:35 AM - L:4968.2[Line:10002>>299] has joined to L:4968.1[Extn:3983]
10/06/2017 9:07:25 AM - [CM503025]: Call(C:4968): Calling T:Line:10002>>299@[Dev:sip:
[email protected]:5060;rinstance=d89aabbcca0e4d36] for L:4968.1[Extn:3983]
10/06/2017 9:07:25 AM - [CM503027]: Call(C:4968): From: Extn:3983 (<sip:
[email protected]:5060>) to T:Line:10002>>299@[Dev:sip:
[email protected]:5060;rinstance=d89aabbcca0e4d36]
10/06/2017 9:07:25 AM - [CM503004]: Call(C:4968): Route 1: from L:4968.1[Extn:3983] to T:Line:10002>>299@[Dev:sip:
[email protected]:5060;rinstance=d89aabbcca0e4d36]
10/06/2017 9:07:25 AM - Call(C:4968): Call from Extn:3983 to *7299 matches outbound rule '3CX Bridge'
10/06/2017 9:07:25 AM - [Flow] Call(C:4968): has built target endpoint: Out#:>>Rule{3CX Bridge}>>*7299 for call from L:4968.1[Extn:3983]
10/06/2017 9:07:25 AM - [CM503010]: Call(C:4968): Making route(s) from Extn:3983 to <sip:*
[email protected]:5060>
10/06/2017 9:07:25 AM - [CM505001]: Endpoint Extn:3983: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [UniFi VoIP Phone 5.0.14.660] PBX contact: [sip:
[email protected]:5060]
10/06/2017 9:07:25 AM - [CM503001]: Call(C:4968): Incoming call from Extn:3983 to <sip:*
[email protected]:5060>
Log from server receiving call:
10/06/2017 9:07:35 AM - Leg L:32.2[Extn:299] is terminated: Cause: 486 Busy Here/INVITE from 192.168.200.110:36462
10/06/2017 9:07:35 AM - L:32.1[Line:10002<<+*73983] forwards call from Extn:299 to VMail:999 based on rule Fwd[Available/Busy]
10/06/2017 9:07:35 AM - L:32.1[Line:10002<<+*73983] failed to reach Extn:299, reason Busy
10/06/2017 9:07:35 AM - Call to T:Extn:299@[Dev:sip:
[email protected]:36462;line=leinmx36] from L:32.1[Line:10002<<+*73983] failed, cause: Cause: 486 Busy Here/INVITE from 192.168.200.110:36462
10/06/2017 9:07:26 AM - [CM505001]: Endpoint Extn:299: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [snom715/8.9.3.66] PBX contact: [sip:
[email protected]:5060]
10/06/2017 9:07:26 AM - [CM503002]: Call(C:32): Alerting Extn:299 by contact <sip:
[email protected]:36462>
10/06/2017 9:07:26 AM - [CM503025]: Call(C:32): Calling T:Extn:299@[Dev:sip:
[email protected]:36462;line=leinmx36] for L:32.1[Line:10002<<+*73983]
10/06/2017 9:07:26 AM - [CM503027]: Call(C:32): From: Line:10002<<+*73983 ("TJ Berry" <sip:*
[email protected]:5060>) to T:Extn:299@[Dev:sip:
[email protected]:36462;line=leinmx36]
10/06/2017 9:07:26 AM - [CM503004]: Call(C:32): Route 1: from L:32.1[Line:10002<<+*73983] to T:Extn:299@[Dev:sip:
[email protected]:36462;line=leinmx36]
10/06/2017 9:07:26 AM - [Flow] Call(C:32): has built target endpoint: Extn:299 for call from L:32.1[Line:10002<<+*73983]
10/06/2017 9:07:26 AM - [Flow] Target endpoint for 299 is Extn:299