error 437: Mismatched allocation: wrong transaction ID

[Nabeel]

Hi,

Please help me fix the following error in Coturn:

14: handle_udp_packet: New UDP endpoint: local addr 162.239.6.207:3478, remote addr 188.29.154.28:24951
14: IPv4. Local relay addr: 162.239.6.207:57759
14: session 001000000000000001: new, realm=<>, username=<>, lifetime=600
14: session 001000000000000001: realm <> user <>: incoming packet ALLOCATE processed, success
14: session 001000000000000001: realm <> user <>: incoming packet message processed, error 437: Mismatched allocation: wrong transaction ID

Nabeel

[Nabeel]

Anybody there? Need help with this urgently please. Everything was working then suddenly this problem started out of nowhere?

[Nabeel]

Hi,

Please let me know where the TURN sessions are stored? Perhaps I can delete them manually to see if it solves the error. I reinstalled coturn on multiple machines, reinstalled SIP server on multiple machines, reverted the SIP database from a previous backup and reverted to previously working versions of the client, but none of that has solved this extremely strange error. I am completely lost now as to the cause, please let me know what I can do. I installed coturn from build on CentOS 7 with 2 IP addresses. Everything was working correctly, I don't know of any changes which could cause this.

Nabeel

On 8 Aug 2017 5:29 pm, "Nabeel" <nabeel...@gmail.com> wrote:

Anybody there? Need help with this urgently please. Everything was working then suddenly this problem started out of nowhere?

--
You received this message because you are subscribed to the Google Groups "TURN Server (Open-Source project)" group.
To unsubscribe from this group and stop receiving emails from it, send an email to turn-server-project-rfc5766-turn-server+unsubscribe@googlegroups.com.
To post to this group, send email to turn-server-project-rfc5766-turn-...@googlegroups.com.
Visit this group at https://groups.google.com/group/turn-server-project-rfc5766-turn-server.
For more options, visit https://groups.google.com/d/optout.

[shakeeb]

Hi Nabeel,

Are you getting "error 437"  for all the requests or sometimes? Is it possible to test using TCP instead of UDP? Can you reproduce the issue with the test client provided with the Turnserver?

I think the error may come because of not releasing allocation ( de allocation) properly. For UDP you need to release allocation otherwise if turnserver get the request from the same IP and PORT it will give the error message. 

I think Turnserver keep the session in memory, not in any table so no way to clean it manually but you can change the source code and discard this check ( not recommended, it will break RFC, can be done only for testing.)

Thanks,

Shakeeb

[Nabeel]

Hi Shakeeb,

Thanks for your reply. I get the error on almost all of the requests; rarely, the error simply states 'allocation timeout'. My client uses UDP only so I have not tested with TCP. I will try the test client provided with the Turnserver. Please let me know how the allocation can be released? Is this done by the client or the server? Where in the source can this check be disabled for testing?

Nabeel

To post to this group, send email to turn-server-project-rfc5766-turn-s...@googlegroups.com.

Visit this group at https://groups.google.com/group/turn-server-project-rfc5766-turn-server.
For more options, visit https://groups.google.com/d/optout.

[Nabeel]

I tested using the test client provided with Turn server and the results show 100% packet loss. There are no received packets. This occurs with both UDP and TCP tests. There are no firewalls on the server. The log is as below:

turnutils_uclient -v -D -n 1000 -m 10 -l 171 -e 127.0.0.1 -g -X $@ 162.XXX.X.202

... 

8: start_mclient: msz=10, tot_send_msgs=1774, tot_recv_msgs=0, tot_send_bytes ~ 303354, tot_recv_bytes ~ 0
9: start_mclient: msz=10, tot_send_msgs=2277, tot_recv_msgs=0, tot_send_bytes ~ 389367, tot_recv_bytes ~ 0
10: start_mclient: msz=10, tot_send_msgs=2781, tot_recv_msgs=0, tot_send_bytes ~ 475551, tot_recv_bytes ~ 0
11: start_mclient: msz=10, tot_send_msgs=3283, tot_recv_msgs=0, tot_send_bytes ~ 561393, tot_recv_bytes ~ 0
12: start_mclient: msz=10, tot_send_msgs=3784, tot_recv_msgs=0, tot_send_bytes ~ 647064, tot_recv_bytes ~ 0
13: start_mclient: msz=10, tot_send_msgs=4291, tot_recv_msgs=0, tot_send_bytes ~ 733761, tot_recv_bytes ~ 0
14: start_mclient: msz=10, tot_send_msgs=4793, tot_recv_msgs=0, tot_send_bytes ~ 819603, tot_recv_bytes ~ 0
15: start_mclient: msz=10, tot_send_msgs=5294, tot_recv_msgs=0, tot_send_bytes ~ 905274, tot_recv_bytes ~ 0
16: start_mclient: msz=10, tot_send_msgs=5801, tot_recv_msgs=0, tot_send_bytes ~ 991971, tot_recv_bytes ~ 0
17: start_mclient: msz=10, tot_send_msgs=6303, tot_recv_msgs=0, tot_send_bytes ~ 1077813, tot_recv_bytes ~ 0
18: start_mclient: msz=10, tot_send_msgs=6804, tot_recv_msgs=0, tot_send_bytes ~ 1163484, tot_recv_bytes ~ 0
19: start_mclient: msz=10, tot_send_msgs=7305, tot_recv_msgs=0, tot_send_bytes ~ 1249155, tot_recv_bytes ~ 0
20: start_mclient: msz=10, tot_send_msgs=7812, tot_recv_msgs=0, tot_send_bytes ~ 1335852, tot_recv_bytes ~ 0
21: start_mclient: msz=10, tot_send_msgs=8314, tot_recv_msgs=0, tot_send_bytes ~ 1421694, tot_recv_bytes ~ 0
22: start_mclient: msz=10, tot_send_msgs=8817, tot_recv_msgs=0, tot_send_bytes ~ 1507707, tot_recv_bytes ~ 0
23: start_mclient: msz=10, tot_send_msgs=9317, tot_recv_msgs=0, tot_send_bytes ~ 1593207, tot_recv_bytes ~ 0
24: start_mclient: msz=10, tot_send_msgs=9611, tot_recv_msgs=0, tot_send_bytes ~ 1643481, tot_recv_bytes ~ 0
25: start_mclient: msz=10, tot_send_msgs=9791, tot_recv_msgs=0, tot_send_bytes ~ 1674261, tot_recv_bytes ~ 0
26: start_mclient: msz=10, tot_send_msgs=9958, tot_recv_msgs=0, tot_send_bytes ~ 1702818, tot_recv_bytes ~ 0
27: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
28: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
29: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
30: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
31: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
32: start_mclient: msz=10, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
33: done, connection 0x7f05a849a010 closed.
33: start_mclient: msz=9, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
33: done, connection 0x7f05a84bb010 closed.
33: done, connection 0x7f05a8560010 closed.
33: done, connection 0x7f05a851e010 closed.
33: done, connection 0x17dd2a0 closed.
33: done, connection 0x17bc600 closed.
34: start_mclient: msz=4, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
35: start_mclient: msz=4, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
35: done, connection 0x7f05a8581010 closed.
35: done, connection 0x7f05a84dc010 closed.
36: start_mclient: msz=2, tot_send_msgs=10000, tot_recv_msgs=0, tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
36: done, connection 0x7f05a84fd010 closed.
36: done, connection 0x7f05a853f010 closed.
36: start_mclient: tot_send_msgs=10000, tot_recv_msgs=0
36: start_mclient: tot_send_bytes ~ 1710000, tot_recv_bytes ~ 0
36: Total transmit time is 35
36: Total lost packets 10000 (100.000000%), total send dropped 0 (0.000000%)
36: Average round trip delay 0.000000 ms; min = 4294967295 ms, max = 0 ms
36: Average jitter -nan ms; min = 4294967295 ms, max = 0 ms

[Nabeel]

After adding -y to the command, received packets are also shown. However, I still get the '437 Mismatched Allocation' error, or allocation timeout, which looks like this: 

32: handle_udp_packet: New UDP endpoint: local addr 162.XXX.X.202:3478, remote addr 188.29.164.18:52225

32: IPv4. Local relay addr: 162.XXX.X.202:59591

32: session 001000000000000002: new, realm=<>, username=<>, lifetime=600

32: session 001000000000000002: realm <> user <>: incoming packet ALLOCATE processed, success

64: session 001000000000000002: refreshed, realm=<>, username=<>, lifetime=0

64: session 001000000000000002: realm <> user <>: incoming packet REFRESH processed, success

65: session 001000000000000002: closed (2nd stage), user <> realm <> origin <>, local 162.XXX.X.202:3478, remote 188.29.164.18:52225, reason: allocation timeout

In the client log, there is this error:

ice: Recv error response: 10.32.184.32:7078 <-- 162.XXX.X.202:3478 [f296795d534ae8c603f985e6] 

Nabeel 

[Nabeel]

I ran the netstat command and found that all UDP connections/interfaces are duplicated. Please see below. Rebooting or killing the turnserver process or restarting the server does not solve this issue. Please advise how the duplicate connections can be removed?

 

[root@server1 ~]# netstat -lnptu | grep turnserver 

tcp        0      0 162.XXX.X.213:3478      0.0.0.0:*               LISTEN      18802/turnserver
tcp        0      0 162.XXX.X.202:3478      0.0.0.0:*               LISTEN      18802/turnserver
tcp        0      0 162.XXX.X.213:3479      0.0.0.0:*               LISTEN      18802/turnserver
tcp        0      0 162.XXX.X.202:3479      0.0.0.0:*               LISTEN      18802/turnserver
tcp        0      0 127.0.0.1:5766              0.0.0.0:*               LISTEN      18802/turnserver
udp        0      0 162.XXX.X.213:3478      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.213:3478      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.202:3478      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.202:3478      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.213:3479      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.213:3479      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.202:3479      0.0.0.0:*                                18802/turnserver
udp        0      0 162.XXX.X.202:3479      0.0.0.0:*                                18802/turnserver

[Nabeel]

Attached to this message are complete logs from my tests using Coturn and test client included with Turn server. The logs are for both TCP and UDP tests with the uclient. 

The TCP test additionally states in Coturn log: 'reason: TCP connection closed by client (callback)'. However, I think this does not mean the uclient is the cause because prior to that it sent lifetime=600 and lifetime=300.

I'm hoping that someone can help resolve this issue from the logs attached.

Nabeel

[Nabeel]

At least can somebody please confirm that duplicate UDP interfaces like these below are not normal for Coturn?

[Nabeel]

I just checked the command: lsof -n | grep turnserve | grep 'TCP\|UDP' and the results show 175 lines of various interfaces/connections for Coturn. Some of them have two different PIDs, which is strange. Please see the attached file with these results. Surely this can't be normal? Can this cause the allocation errors I'm experiencing? How can all these connections be cleared?

[shakeeb]

>>At least can somebody please confirm that duplicate UDP interfaces like these below are not normal for Coturn?

yes. It is normal if you have multiple cores.

Can you please give me the output of the following commands 

#netstat  -suna

#ulimit -a

You should not have udp error and have sufficient file descriptors to run turnserver properly. If you have udp error , set default and maximum socket memory properly.

Thanks,

Shakeeb

[Nabeel]

Hi Shakeeb,

Please see below:

[root@server1 ~]# netstat -suna
IcmpMsg:
    InType0: 11
    InType3: 318
    InType8: 180
    InType11: 6
    OutType0: 180
    OutType3: 681
Udp:
    452381 packets received
    785 packets to unknown port received.
    0 packet receive errors
    436635 packets sent
    0 receive buffer errors
    0 send buffer errors
UdpLite:
IpExt:
    InNoRoutes: 106
    InBcastPkts: 40339
    InOctets: 177512112
    OutOctets: 192456158
    InBcastOctets: 12133150
    InNoECTPkts: 421596
    InECT0Pkts: 397014
    InCEPkts: 1

What's the significance of this line:

 785 packets to unknown port received.

[root@server1 ~]# ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 3818
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1048576
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 3818
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Do you think any of these should be increased? What about 'max locked memory (kbytes, -l) 64'?

Nabeel

[shakeeb]

Hi Nabeel,

Sorry for the delay. Everything seems normal. There were no receive buffer errors. File descriptor size is large 

You can ignore the error "785 packets to unknown port received." as it has no relation to the error. 

the unknown port error happens when the system receives for the port which is not opened by any application.

It is difficult to guess about the error you are facing without close investigation. 

Turn server is not a memory hungry program. So I think the issue has no relation to the  "max locked memory"

Thanks,

Shakeeb