I could reproduce strange behaviour today myself.
Called out from 3CX Prod Server Extension via SIP trunk to an extension on another 3CX Test Server.
Caller calls, phone rings, everything ok.
Next time the phone rings only one time then stops ringing, call on both sides ends.
Another time phone does not ring on callees side, caller is forwarded to mailbox.
Found some mysterious 404 not found and timeout entries in log (while always calling the same destination number), see log file here when the caller is rerouted to the mailbox:
<begin log files>
Callers side (originating system)
22.06.2018 09:51:56:499 | [CM503001]: Call(C:47): Incoming call from Extn:<ExtensionNumber> to <sip:<TargetNumber>@<Name.3CX.tld>:5060>
22.06.2018 09:51:56:499 | [CM500002]: Call(C:47): Info on incoming INVITE from Extn:<ExtensionNumber>:
Invite-IN Recv Req INVITE from 127.0.0.1:5080 tid=Pjb96c032694a24d80934358dfca4825fa Call-ID=99b9f9e78e7b49a5b64b886327235a12:
INVITE sip:<TargetNumber>@127.0.0.1:5060;transport=UDP;tag3cx=be4795dd13474c4199b08e332267c01a SIP/2.0
Max-Forwards: 69
Record-Route: <sip:
[email protected]:5080;user=proxy;uri=clnt.1-965c6299bd1946128421016dee1cbd8a>
Contact: "<From Name>" <sip:<ExtensionNumber>@127.0.0.1:5060;rinstance=1-965c6299bd1946128421016dee1cbd8a>
To: <sip:<TargetNumber>@<Name.3CX.tld>;tag3cx=be4795dd13474c4199b08e332267c01a>
From: "<From Name>"<sip:<ExtensionNumber>@<Name.3CX.tld>>;tag=fff55e8e240046159297d559a1a242bd
Call-ID: 99b9f9e78e7b49a5b64b886327235a12
CSeq: 6480 INVITE
Session-Expires: 1800
Min-SE: 90
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Type: application/sdp
Proxy-Authorization: Digest username="if96e7c",realm="3CXPhoneSystem",nonce="414d535c113d3b9c69:218663e09e8f823c045944f59ea86d77",uri="sip:<TargetNumber>@<Name.3CX.tld>;transport=tcp;tag3cx=be4795dd13474c4199b08e332267c01a",response="3b0ff4fa0c689dcdcbfb40177bf18163",algorithm=MD5
Supported: replaces, 100rel, timer, norefersub
User-Agent: 3CXPhone for Windows 15.5.12227.5
Content-Length: 425
v=0
o=- 3738649914 3738649914 IN IP4 192.168.1.26
s=pjmedia
c=IN IP4 127.0.0.1
b=AS:84
t=0 0
a=X-nat:0
m=audio 11052 RTP/AVP 3 18 0 8 9 96
c=IN IP4 127.0.0.1
b=TIAS:64000
b=AS:84
a=sendrecv
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1
22.06.2018 09:51:56:500 | [CM505001]: Endpoint Extn:<ExtensionNumber>: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CXPhone for Windows 15.5.12227.5] PBX contact: [sip:<ExtensionNumber>@127.0.0.1:5060]
22.06.2018 09:51:56:500 | [CM503010]: Call(C:47): Making route(s) from Extn:<ExtensionNumber> to <sip:<TargetNumber>@<Name.3CX.tld>:5060>
22.06.2018 09:51:56:500 | [Flow] Target endpoint for <TargetNumber> is Out#:>>Rule{<TrunkRuleName>}>><TargetNumber>
22.06.2018 09:51:56:500 | [Flow] Call(C:47): has built target endpoint: Out#:>>Rule{<TrunkRuleName>}>><TargetNumber> for call from L:47.1[Extn:<ExtensionNumber>]
22.06.2018 09:51:56:500 | Call(C:47): Call from Extn:<ExtensionNumber> to <TargetNumber> matches outbound rule '<TrunkRuleName>'
22.06.2018 09:51:56:500 | Line limit check: Current # of calls for line Lc:10003(
@sip Trunk[<sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060>]) is 0; limit is 64
22.06.2018 09:51:56:500 | [CM503004]: Call(C:47): Route 1: from L:47.1[Extn:<ExtensionNumber>] to T:Line:10003>><TargetNumber>@[Dev:sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060]
22.06.2018 09:51:56:500 | [CM503027]: Call(C:47): From: Extn:<ExtensionNumber> ("<From Name>" <sip:<ExtensionNumber>@<Name.3CX.tld>:5060>) to T:Line:10003>><TargetNumber>@[Dev:sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060]
22.06.2018 09:51:56:529 | [CM503025]: Call(C:47): Calling T:Line:10003>><TargetNumber>@[Dev:sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060] for L:47.1[Extn:<ExtensionNumber>]
22.06.2018 09:51:57:147 | [CM500002]: Unidentified incoming call. Review INVITE and adjust source identification:
Invite-UNK Recv Req INVITE from <VoIPProviderPublicIP>:5060 tid=e6a1116aa990530a61f95f2676e95a2d Call-ID=yoLSB8QBEKbQ0xEW_v26VA..~2o:
INVITE sip:<InviteSIP>@<3CXPublicIP>:5060 SIP/2.0
Via: SIP/2.0/UDP <VoIPProviderPublicIP>:5060;branch=z9hG4bK-524287-1---e6a1116aa990530a61f95f2676e95a2d;rport=5060
Via: SIP/2.0/UDP <VoIPProviderPublicIP>:5071;branch=z9hG4bK-uyyh74waod56zpys;rport=5071
Max-Forwards: 69
Record-Route: <sip:<VoIPProviderPublicIP>:5060;transport=udp;lr;pinhole=UDP:<3CXPublicIP>:5060>
Contact: <sip:<VoIPProviderPublicIP>:5071>
To: <sip:<TargetNumber>@<VoIPProviderFQDN>>
From: <SourceDID> <sip:<SourceDID>@<VoIPProviderFQDN>>;tag=il7r5vwczh62i7ho.o
Call-ID: yoLSB8QBEKbQ0xEW_v26VA..~2o
CSeq: 652 INVITE
Expires: 300
Allow: INVITE, ACK, BYE, CANCEL, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS, UPDATE
Content-Disposition: session
Content-Type: application/sdp
User-Agent: Sippy
h323-conf-id: 2971849412-961481925-4226754372-4226754372
cisco-GUID: 2971849412-961481925-4226754372-4226754372
Content-Length: 252
v=0
o=Sippy 1208912196286077236 1 IN IP4 <VoIPProviderPublicIP>
s=3cxPS Audio call
t=0 0
m=audio 9072 RTP/AVP 0 8 3 101
c=IN IP4 <3CXPublicIP>
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
22.06.2018 09:51:57:534 | [CM503002]: Call(C:47): Alerting Line:10003>><TargetNumber> by contact <sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060>
22.06.2018 09:51:57:534 | [CM505003]: Provider:[SIP Trunk] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [] PBX contact: [sip:<TrunkMainNumber>@<3CXPublicIP>:5060]
22.06.2018 09:51:58:766 | L:47.2[Line:10003>><TargetNumber>] has joined to L:47.1[Extn:<ExtensionNumber>]
22.06.2018 09:51:58:767 | [CM503007]: Call(C:47): Extn:<ExtensionNumber> has joined, contact <sip:<ExtensionNumber>@127.0.0.1:5060>
22.06.2018 09:51:58:767 | [CM503007]: Call(C:47): Line:10003>><TargetNumber> has joined, contact <sip:<TrunkMainNumber>@<VoIPProviderFQDN>:5060>
22.06.2018 09:52:09:489 | Leg L:47.1[Extn:<ExtensionNumber>] is terminated: Cause: BYE from 127.0.0.1:5080
22.06.2018 09:52:09:489 | [CM503008]: Call(C:47): Call is terminated
Callees side (target system)
22.06.2018 09:51:57:708 | [CM503003]: Call(C:28): Call to <sip:<ExtensionNumber>@<TargetCustomer.3cx.tld>:5060> has failed; Cause:
404 Not Found/INVITE from 127.0.0.1:5080
22.06.2018 09:51:57:708 | Call to T:Extn:<ExtensionNumber>@[Dev:sip:<SIP>@127.0.0.1:5060;rinstance=1-r0taqqj0mzuvthqdpdmuo5z.-lruoors;inst="d04d0359",Dev:sip:<SIP>@127.0.0.1:5488;rinstance=1f1afc9c172e9b9c] from L:28.1[Line:10003<<<FromNumber>] failed, cause:
Cause: 404 Not Found/INVITE from 127.0.0.1:5080
22.06.2018 09:51:58:433 | [CM503003]: Call(C:28): Call to <sip:<ExtensionNumber>@<TargetCustomer.3cx.tld>:5060> has failed; Cause: 408 Request Timeout/INVITE from 127.0.0.1:5488
22.06.2018 09:51:58:433 | Call to T:Extn:<ExtensionNumber>@[Dev:sip:<ExtensionNumber>@127.0.0.1:5488;rinstance=1f1afc9c172e9b9c] from L:28.1[Line:10003<<<FromNumber>] failed, cause: Cause: 408 Request Timeout/INVITE from 127.0.0.1:5488
<end log files>
How come the target is found some times some times not?