Hello,
Can someone help me to understand this error given by TM Module?
I have a Kamailio SIP Proxy running in front of a few Asterisk boxes. On average, he is processing 70-80 requests per second. The problem is that sometimes (90-100 times/day) - I see such errors in the logs:
500 I'm terribly sorry, server error occurred (1/SL) 477 Unfortunately error on sending to next hop occurred (477/TM)
Trying to investigate this error - I found that this is happening randomly and for INVITES coming from the Asterisk Box. For ex, the INVITE below:
192.168.180.10 - Kamailio Server 192.168.180.36 - Asterisk Server
INVITE sip:1001@192.168.180.10:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.180.36:5060;branch=z9hG4bK4624ab4e;rport Max-Forwards: 70 From: "Anonymous" sip:anonymous@192.168.180.10;tag=as11bed8a6 To: sip:1001@192.168.180.10:5060 Contact: sip:anonymous@192.168.180.36:5060 Call-ID: 0ea8535d3a5ecaa6432912a2566c807f@192.168.180.10 CSeq: 102 INVITE User-Agent: MYCOMPANY Date: Mon, 28 Jan 2019 16:01:56 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 251
v=0 o=SIP 2139556641 2139556641 IN IP4 192.168.180.36 s=MYCOMPANY PBX c=IN IP4 192.168.180.36 t=0 0 m=audio 14674 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv
Kamailio is replying back with 100 Trying and then with 500/477 errors:
SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.180.36:5060 ;branch=z9hG4bK4624ab4e;rport=5060;received=192.168.180.36 From: "Anonymous" sip:anonymous@192.168.180.10;tag=as11bed8a6 To: sip:1001@192.168.180.10:5060 Call-ID: 0ea8535d3a5ecaa6432912a2566c807f@192.168.180.10 CSeq: 102 INVITE Server: MYCOMPANY SBC Content-Length: 0
SIP/2.0 500 I'm terribly sorry, server error occurred (1/SL) Via: SIP/2.0/UDP 192.168.180.36:5060 ;branch=z9hG4bK4624ab4e;rport=5060;received=192.168.180.36 From: "Anonymous" sip:anonymous@192.168.180.10;tag=as11bed8a6 To: sip:1001@192.168.180.10:5060;tag=9dd61ff61e802d8e2bef5f14621ef3c2.2e93 Call-ID: 0ea8535d3a5ecaa6432912a2566c807f@192.168.180.10 CSeq: 102 INVITE Server: MYCOMPANY SBC Content-Length: 0
SIP/2.0 477 Unfortunately error on sending to next hop occurred (477/TM) Via: SIP/2.0/UDP 192.168.180.36:5060 ;branch=z9hG4bK4624ab4e;rport=5060;received=192.168.180.36 From: "Anonymous" sip:anonymous@192.168.180.10;tag=as11bed8a6 To: sip:1001@192.168.180.10:5060;tag=a6a1c5f60faecf035a1ae5b6e96e979a-2e93 Call-ID: 0ea8535d3a5ecaa6432912a2566c807f@192.168.180.10 CSeq: 102 INVITE Server: MYCOMPANY SBC Content-Length: 0
And I cannot actually get what is wrong with this INVITE - and why Kamailio cannot process it? Other calls for the same extension are working fine, this is happening randomly and with different extensions. Load on the server is very low:
[root@kamailio root]# nproc 8
[root@kamailio root]# uptime 17:49:15 up 8 days, 21:17, 6 users, load average: 0.66, 0.56, 0.52
[root@kamailio root]# free -m total used free shared buff/cache available Mem: 7981 4283 142 818 3556 2581 Swap: 6141 137 6004
[root@kamailio root]# ss -4 -n -l | grep 5060 udp UNCONN 0 0 192.168.180.10 :5060 *:* udp UNCONN 0 0 127.0.0.1:5060 *:* tcp LISTEN 0 128 192.168.180.10 :5060 *:* tcp LISTEN 0 128 127.0.0.1:5060 *:*
In the kamailio logs I found that kamailio was able to get the contact address: kamailio[18168]: INFO: {INVITE (1) Contacts loaded for 1001} kamailio[18168]: INFO: {INVITE (1) t_next_contacts - Only one contact found for 1001, calling} kamailio[18168]: INFO: {INVITE (1) Next Hop: <192.168.180.211:3126>}
I don't know how to reproduce this - I tried to disconnect the phone from the power source - and made a call to that extension, and it is giving timeouts - like it is supposed to be.
What could be the problem and how I can fix it? Thank You.