Proximity Chat lags and hitches in groups of 2 or more.

Question

Proximity Chat lags and hitches in groups of 2 or more.

Hhartle opened this issue 3 years ago · 34 comments

Hhartle commented 3 years ago

Please read the FAQ before submitting a bug report!

Bug description
I'm currently hosting a server for a YouTube series where we have ~ 14 people online at the same time. When we did our first session stress test, we had really bad issues with audio hitching mid sentence, as well as audio lagging so bad that it was unrecognizable using proximity chat with large numbers of people. Surprisingly, despite the audio lag in large groups, when the group was split up we noticed the following:

Even with 14 people on the server, the server did not exhibit any block lag, even when audio lag was occurring.
Audio Lag was virtually non existent with all 14 people split into groups of 2 using proximity chat.
With groups of 3 there tended to be slightly more issues with proximity chat.
Groups of 4 or more in the same proximity chat rendered audio virtually unrecognizable.

We also tried using the group feature, which does not work for our series, but yielded similar results to proximity chat with audio becoming unrecognizable as more people were added (~ 5 people in groups)

I haven't had a chance to browse through the source code, but it's interesting that the "separate" proximity chats can work fine, but as you add more people to them it breaks down. (I.e. 7 proximity chats of 2 players works great, but 2 proximity chats of 7 players struggles).

Currently using a hosting service that only offers single core cpus. I know that this was a possible reason for the lag. Did some cursory searches and have not been able to find any that offer multi core cpus.

System Stats from my server host's website:
CPU: 4.4 - 5 GHz Processor (High Priority)
Ram: 5 GBs DDR4 2400 MHz
SSD: NVMe 2500+ MB r/w

Steps to reproduce the issue

Number of players on server does not matter.
If in groups of 2 despite number of players voice chat works fine.
As more users join the proximity groups the voice chat lags and audio problems occur.

Expected behavior
Chat does not hitch and or lag when talking in proximity with more than 2 users.

Log files
The two common logs I've been seeing is this, but not sure if it's even related:
[22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.net.PlainDatagramSocketImpl.send(Native Method) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.net.DatagramSocket.send(DatagramSocket.java:693) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.ClientConnection.send(ClientConnection.java:49) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.processProximityPacket(Server.java:214) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.access$700(Server.java:20) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server$ProcessThread.run(Server.java:155) [22:25:55] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: java.io.IOException: Operation not permitted (sendto failed)

[23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: java.io.IOException: Operation not permitted (sendto failed) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.net.PlainDatagramSocketImpl.send(Native Method) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.net.DatagramSocket.send(DatagramSocket.java:693) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.ClientConnection.send(ClientConnection.java:49) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.sendPacket(Server.java:253) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.keepAlive(Server.java:228) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.access$100(Server.java:20) [23:03:17] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server$ProcessThread.run(Server.java:117)

Through the gist dump I've also found

[21:04:55] [VoiceChatPacketProcessingThread/INFO]: Player timed out [21:04:55] [VoiceChatPacketProcessingThread/INFO]: Reconnecting player Player7 [21:04:55] [VoiceChatPacketProcessingThread/INFO]: Sent secret to Player7 [21:04:55] [VoiceChatPacketProcessingThread/INFO]: Successfully authenticated player

Here is the gist dump: https://gist.github.com/Hhartle/ce1e8c489e7b37aa770cdf8498660586#file-gistfile1-txt

Versions

Minecraft 1.16.5
fabric-api 0.34.6
During the test: 1.16.5 - 1.3.11 Simple Voice Chat

We have also tried the most recent version of simple, 1.16.5 - 1.4.4. This did not seem to fix the problems we were having. Albeit we only were able to test with 5 players. However we did notice a new problem that I had not seen before where peoples mics would cut out halfway through a sentence. This was a problem that did not exists on 1.3.11

Other mods
We are not running any additional mods on the server.

Screenshots (Optional)
Screenshots of the issue.

Hhartle · Answer 1 · 2021-06-12T12:54:43.000Z

@henkelmax Reached out to my server host. Looks like port forwarding is allowed. I've switched ports in my config to a new open port to ensure that someone else was not trying to use that port at the same time. Was able to get another person online to test. Audio quality sounds fine in groups of two but still getting the same errors as above:
[STDERR]: java.io.IOException: Operation not permitted (sendto failed)

henkelmax · Answer 2 · 2021-06-12T13:00:48.000Z

However we did notice a new problem that I had not seen before where peoples mics would cut out halfway through a sentence. This was a problem that did not exists on 1.3.11

Yes, this is intentional, if the server laggs behind sending the packets, it will discard some packets to compensate the delay.

Can I see your voicechat server config file?

Hhartle · Answer 3 · 2021-06-12T13:21:19.000Z

Can I see your voicechat server config file?

#Sat Jun 12 08:42:54 EDT 2021
port=8526
bind_address=0.0.0.0
voice_distance=32.0
voice_fade_distance=16.0
codec=VOIP
enable_groups=true
mtu_size=1024
keep_alive=1000

This is the contents of my config file - was going to add the file but looks like the file type isn't supported.

henkelmax · Answer 4 · 2021-06-12T14:01:43.000Z

Thank you!
Have you tried binding to your servers IP address?

Hhartle · Answer 5 · 2021-06-12T14:29:06.000Z

Unsure why I didn't think to do that. Just tried it with two people and still seeing the error, although the audio quality with only two of us was still fine! Hopefully I can get more online later to test with a larger group.

henkelmax · Answer 6 · 2021-06-13T20:45:54.000Z

Do the errors only occur when specific players are talking in the voice chat or does it happen every time?

Duskeeb · Answer 7 · 2021-06-14T05:39:50.000Z

I'm having the same problem this guy was having, I've tried the solutions suggested and it has not helped. It spits out these errors:
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: java.net.SocketException: Operation not permitted
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send0(Native Method)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.sendFromNativeBuffer(DatagramChannelImpl.java:897)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:859)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:817)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.blockingSend(DatagramChannelImpl.java:849)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramSocketAdaptor.send(DatagramSocketAdaptor.java:217)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/java.net.DatagramSocket.send(DatagramSocket.java:531)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.ClientConnection.send(ClientConnection.java:39)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.sendPacket(Server.java:255)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.sendKeepAlives(Server.java:241)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server$ProcessThread.run(Server.java:115)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: java.net.SocketException: Operation not permitted
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send0(Native Method)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.sendFromNativeBuffer(DatagramChannelImpl.java:897)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:859)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:817)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.blockingSend(DatagramChannelImpl.java:849)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramSocketAdaptor.send(DatagramSocketAdaptor.java:217)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/java.net.DatagramSocket.send(DatagramSocket.java:531)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.ClientConnection.send(ClientConnection.java:39)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.sendPacket(Server.java:255)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server.sendKeepAlives(Server.java:241)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.Server$ProcessThread.run(Server.java:115)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: java.net.SocketException: Operation not permitted
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send0(Native Method)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.sendFromNativeBuffer(DatagramChannelImpl.java:897)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:859)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.send(DatagramChannelImpl.java:817)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramChannelImpl.blockingSend(DatagramChannelImpl.java:849)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/sun.nio.ch.DatagramSocketAdaptor.send(DatagramSocketAdaptor.java:217)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at java.base/java.net.DatagramSocket.send(DatagramSocket.java:531)
[14.06 01:29:55] [Server] [VoiceChatPacketProcessingThread/INFO]: [STDERR]: at de.maxhenkel.voicechat.voice.server.ClientConnection.send(ClientConnection.java:39)

My config files are as follows:
codec=VOIP
voice_fade_distance=16.0
port=25605
mtu_size=1024
voice_distance=32.0
keep_alive=1000
bind_address=(server IP, don't wanna share it)
enable_groups=true

henkelmax · Answer 8 · 2021-06-14T08:59:05.000Z

@Duskeeb Please use GitHub gist for logs

Hhartle · Answer 9 · 2021-06-14T12:57:01.000Z

@henkelmax Very difficult to tell but it seems to happen regardless of player. I'll try to do some more digging here in a bit.
Is this error typical of server stress or something different?

henkelmax · Answer 10 · 2021-06-14T13:01:57.000Z

I have only seen this issue on servers, where hosters were not allowing opening other ports. But usually nothing works at all in these cases.

Hhartle · Answer 11 · 2021-06-14T13:07:10.000Z

Alright, I'll reach back out to my server host to see if they can do more investigating on their end too

Hhartle · Answer 12 · 2021-06-14T13:57:01.000Z

After talking to my server host, we confirmed that the port is open, and even after changing ports again still getting this error.

henkelmax · Answer 13 · 2021-06-14T14:14:44.000Z

That's so strange... I have to look deeper into it. I'll get back to you once I have something.
Please let me know if you have something that could help solving the problem.

henkelmax · Answer 14 · 2021-06-15T16:50:37.000Z

I think I've found the cause of the issue. @Hhartle would you please try this version:

voicechat-1.16.5-1.5.3-test.zip

Don't forget to unzip it first :D

Hhartle · Answer 15 · 2021-06-15T18:54:44.000Z

@henkelmax
It seemed like it was working better for about 5 minutes, and then the error happened again. Another 2 min of talking with no errors, and then another error. Pretty strange but seems to be in the right direction at least.

Here's my gist logs: https://gist.github.com/Hhartle/10357e9e0df50a5ec48bbae67131987d

henkelmax · Answer 16 · 2021-06-15T19:22:46.000Z

I think this is the issue: https://stackoverflow.com/a/62624206/9889252

In my case the failure was due to conntrack filling up, which isn't specific to Java and has been reported elsewhere (1, 2). One simple way around the problem is to make all udp traffic bypass conntrack:

iptables -I PREROUTING -t raw -p udp -j NOTRACK
iptables -I OUTPUT -t raw -p udp -j NOTRACK

I don't know if you can fix this on your own, since you are using a Minecraft server hoster.

Hhartle · Answer 17 · 2021-06-16T12:45:21.000Z

Isn't that the exact same error?

My apologies. You're right, that is the same error from yesterday after the test version. I meant that the path/tracing was different than we were getting originally. Didn't catch that the stack trace yesterday was different than before. I'm on the same page now.

The profiler does not track the voice chat.

Right. I sent a follow up message to them explaining this and also mentioning the issue (https://stackoverflow.com/a/62624206/9889252). I more so meant that this tends to point towards our hypothesis of network issues versus server strength.

I'll let you know what they send back my way.

Hhartle · Answer 18 · 2021-06-16T13:43:33.000Z

@henkelmax Alright, my server host was able to apply the IP table rules suggested in the stack overflow issue. I tested with two of my accounts and am still seeing the same error from my prior gist: https://gist.github.com/Hhartle/2b8a053af6916bf5bb479d0d6a3b35c9

My server host also asked

if an UDP limit might be the cause of this and how many UDP packets does the plugin send? If this is caused by our UDP limit we can definitely increase this to the necessary levels.

Interested to see your thoughts on this. Thanks again for all of your help :)

Hhartle · Answer 19 · 2021-06-16T11:58:02.000Z

I sent this over to my server host. Not sure if they'll be able to do anything on that front, but they did have me time box a 30 min debug session where I was able to get 5 friends on to test the chat during. Server host were really happy with the performance.
Debug Log: https://gist.github.com/Hhartle/75e20d40d1780ae301b70782f2732745
The log file during this session was exorbitantly large sitting at 1.2GB. Had to download a new program just to view it LOL. But I did notice that there was one new error that I was able to find repeated alongside the old errors
https://gist.github.com/Hhartle/2b8a053af6916bf5bb479d0d6a3b35c9

I'm still struggling to understand what the root cause of the lag / hitching is. The server seems to be running super fast. We have no block lag, and if there's only two of us in proximity, even when we have significantly more people online (2 groups of 2 and 1 group of 1) chats for all groups are fine. It's only when we have groups of more than 3 that that audio goes down hill. So strange

henkelmax · Answer 20 · 2021-06-16T12:05:02.000Z

But I did notice that there was one new error that I was able to find repeated alongside the old errors
https://gist.github.com/Hhartle/2b8a053af6916bf5bb479d0d6a3b35c9

Isn't that the exact same error?

Server host were really happy with the performance.
Debug Log: https://gist.github.com/Hhartle/75e20d40d1780ae301b70782f2732745

The profiler does not track the voice chat.

I'm still struggling to understand what the root cause of the lag / hitching is.

It is caused by the server dropping network packets due to the aforementioned issue (https://stackoverflow.com/a/62624206/9889252).

Has your hoster mentioned anything about the conntrack issue?

henkelmax · Answer 21 · 2021-06-16T14:07:41.000Z

if an UDP limit might be the cause of this and how many UDP packets does the plugin send? If this is caused by our UDP limit we can definitely increase this to the necessary levels.

If a player is talking, the server sends a packet every 20 milliseconds to each player that is in the vincinity.
Each packet is smaller than 1024 bytes.

If your hoster has a UDP limit, this is definitely the issue. Please ask them to increase it appropriately.

Hhartle · Answer 22 · 2021-06-17T14:32:16.000Z

Quick Update: The UDP limit has been disabled on my server node as well as the IP Table rule being in place. I've only been able to test this morning with two players so far. Audio sounds good, but I'm still getting the error :(

henkelmax · Answer 23 · 2021-06-17T15:11:16.000Z

If it works with more people, I can patch out the error messages for you...

Hhartle · Answer 24 · 2021-06-17T20:46:03.000Z

Was able to try in a group of 5 just now. Works fine with 2, a little worse with 3, and then 4+ there's tons of voice lag and hitching. CPU seemed to be between 30-60% load whenever I looked.

henkelmax · Answer 25 · 2021-06-17T20:55:09.000Z

I'm sorry, but I'm out of ideas. The last thing you could try is completely resetting your server or moving to another hoster...

njenkins11 · Answer 26 · 2021-06-20T01:26:43.000Z

Also having the same problem too. Two players in proximity / group works perfect; however, the moment a third player joins in, players start to have issues hearing one another due to lag.

Not sure if this would help, but if only two of those three players are talking, it doesn't lag that badly. But once all three players start talking, the lag quickly becomes noticeable.

Server specs:
Xeon Processor at 3.4Ghz
10 GB of DDR4 RAM

Talked to the host already, there is no UDP limit in place.

Version of Mod: 1.4.4 (Forge)

Server Log: https://gist.github.com/Sevenblade11/f22e986472ff375dba1aabf11e68c932

njenkins11 · Answer 27 · 2021-06-20T15:42:51.000Z

We're using Bisect Hosting

henkelmax · Answer 28 · 2021-06-20T16:06:10.000Z

We're using Bisect Hosting

Premium or budget?

njenkins11 · Answer 29 · 2021-06-20T16:55:31.000Z

We're using Bisect Hosting

Premium or budget?

Budget I believe

henkelmax · Answer 30 · 2021-06-20T16:58:23.000Z

Budget I believe

The voice chat only works with the premium one unfortunately.

henkelmax · Answer 31 · 2021-06-20T06:52:01.000Z

Which hoster are you using?

henkelmax · Answer 32 · 2021-06-23T07:22:15.000Z

I'm sorry, but I'm out of ideas. The last thing you could try is completely resetting your server or moving to another hoster...

@Hhartle Any updates on the issue?

Hhartle · Answer 33 · 2021-06-23T14:58:18.000Z

Sorry for the delayed response on this. Looks like it was a networking problem with the specific machine the server was on. I wish I could provide more detail as to why, but after switching server nodes / racks the voice chat is working amazing! Was finally able to test with a group of 10 last night and no audio problems at all! Thank you so much for all of your help! Really appreciate the work you constantly put into this :) Think its safe to close this!

henkelmax · Answer 34 · 2021-06-23T14:59:25.000Z

Awesome to hear that!
Have fun playing :)

Share to