Retransmission timeout error

Asterisk Asterisk SIP
1

We are running Asterisk 16.11.1 in CentOS 7 box with 16 CPU and 65 GB RAM. The calls are timing out with the below message when we do testing with 5 cps. We are not using Realtime and the dialplan is in the extensions.conf file. We are using a simple dialplan for testing and the calls started timing out with Retransmission error on 43rd call onward if number of lines/statements in the dialplan is 17. Issue started experiencing on 68th call when the number of dialplan statements reduces to 12.

exten => 1000,1,Answer()
exten => 1000,n,NoOp(message1)
exten => 1000,n,NoOp(message2)
exten => 1000,n,NoOp(message3)
exten => 1000,n,NoOp(message4)
exten => 1000,n,NoOp(message5)
exten => 1000,n,NoOp(message6)
exten => 1000,n,NoOp(message7)
exten => 1000,n,NoOp(message8)
exten => 1000,n,NoOp(message9)
exten => 1000,n,NoOp(message10)
exten => 1000,n,NoOp(message11)
exten => 1000,n,NoOp(message12)
exten => 1000,n,NoOp(message13)
exten => 1000,n,NoOp(message14)
exten => 1000,n,NoOp(message15)
exten => 1000,n,NoOp(message16)
exten => 1000,n,Playback(mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio&mohaudio)
exten => 1000,n,Hangup()

[2020-06-25 13:36:28.687] WARNING[44639] chan_sip.c: Retransmission timeout reached on transmission 4fdc-48899552-0001-Call71 for seqno 1 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 32122ms with no response
[2020-06-25 13:36:28.695] WARNING[44639] chan_sip.c: Hanging up call 4fdc-48899552-0001-Call71 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2020-06-25 13:36:32.992] WARNING[44639] chan_sip.c: Retransmission timeout reached on transmission 1f89-48900752-0001-Call77 for seqno 1 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 32541ms with no response
[2020-06-25 13:36:32.999] WARNING[44639] chan_sip.c: Hanging up call 1f89-48900752-0001-Call77 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2020-06-25 13:36:38.997] WARNING[44639] chan_sip.c: Retransmission timeout reached on transmission 3558-48902357-0001-Call85 for seqno 1 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 32362ms with no response
[2020-06-25 13:36:39.010] WARNING[44639] chan_sip.c: Hanging up call 3558-48902357-0001-Call85 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2020-06-25 13:36:40.060] WARNING[44639] chan_sip.c: Retransmission timeout reached on transmission 7086-48902552-0001-Call86 for seqno 1 (Critical Response) – See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions

Any help on this will be highly appreciated.

Thanks,
Pradeep

2

This is generally a NAT or firewall problem , not a system load one. It could be a network load problem, but that is unlikely.

Asterisk has sent a final SIP response and has not received an ACK in return. One of:

  • the response failed to reach the peer;
  • the response reached the peer, but the address in the Contact header is not, or is no longer, a valid route back to Asterisk;
  • the response reached the peer, but the peer failed to send an ACK in reply.
3

All we are doing here placing 900 total test calls to the Asterisk server and then Asterisk is just answering these incoming call receiving on the extension 1000 and playing an audio file. In the sip trace captured on the Asterisk server, we don’t see any response messages from Asterisk service for the INVITE request received. No peers configured in Asterisk. Asterisk is able to answer all 900 calls without any issues when we reduce the CPS from 5 to 2 or reduce the number of statements in the dialplan from 17 to 4.

image
image533×754 4.3 KB

4

Please provide the protocol logs from Asterisk, not from wireshark.

Given the calls are incoming to Asterisk, this message definitely relates to the retransmission of a response by Asterisk. and that is confirmed by the reference to critical responses. Does Dialer correctly send ACKs?

5

Also, why are you running benchmarks on a channel driver that is almost unsupported.? chan_sip is only supported by community volunteers, not by Sangoma.

6

Does sip show channel work on the channels involved? I suppose there could be a deadlock, but I can’t see how that would be triggered by the number of Noop dialplan lines. Also, I would have thought that the retransmission timer would be set in same thread as passing the response to the network layer, so I find it difficult to imagine it being set without the packet actually being sent.

Actually, I think the initial transmission of the response will be on the thread running the dialplan, for that call, so if it has deadlocked, I would expect nothing to be logged after the Answer, assuming that you set the verbosity to at least 3, which is advisable in any debugging situation.

I can’t really see anything beyond setting the retransmit timeout and actually sending, that could fail, other than the actual network system call. It could fail between the sip set debug on logging point and the network system call, if there was a memory allocation failure, but setting debug to at least 2 should trigger this message which is pretty much at the point of no return:

        ast_debug(2, "Trying to put '%.11s' onto %s socket destined for %s\n", a
st_str_buffer(data), get_transport_pvt(p), ast_sockaddr_stringify(dst));
7

Yes, the dialer sends the ACKs correctly. We were running with chan_sip since we never had any issues experienced in the past.

8

Please find the attachment for the asterisk service log

asterisklogs1.txt (3.8 MB) asterisklogs2.txt (3.8 MB) asterisklogs3.txt (3.8 MB) asterisklogs4.txt (3.8 MB) asterisklogs5.txt (3.7 MB)

9

I see this debug message for each and every call,

[2020-06-28 20:49:39.850] DEBUG[43900][C-00000001] chan_sip.c: SIP/10.4.21.59-00000000: New call is still down… Trying…
[2020-06-28 20:49:39.850] DEBUG[43900][C-00000001] chan_sip.c: Trying to put ‘SIP/2.0 100’ onto UDP socket destined for 10.4.21.59:5060
[2020-06-28 20:49:39.852] DEBUG[43900] chan_sip.c: Allocating new SIP dialog for ded3-74974897-0001-Call2 - INVITE (No RTP)

[2020-06-28 20:49:39.887] DEBUG[43900][C-00000002] chan_sip.c: SIP/10.4.21.59-00000001: New call is still down… Trying…
[2020-06-28 20:49:39.887] DEBUG[43900][C-00000002] chan_sip.c: Trying to put ‘SIP/2.0 100’ onto UDP socket destined for 10.4.21.59:5060

10

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.