Lavalink icon indicating copy to clipboard operation
Lavalink copied to clipboard

Playback very stutter/laggy

Open cloudwithax opened this issue 3 years ago • 26 comments

Description

Lavalink has been recently very stuttery/laggy on playback of practically everything. I have tested this on multiple server providers and have concluded that this is an issue with Lavalink and not any internal/external factors (networking issues, CPU usage, latency, etc.)

Version info

Client used:

Wavelink 0.9.6

Output of java -version:

java version "13" 2020-03-17
Java(TM) SE Runtime Environment (build 13+36-1461)
Java HotSpot(TM) 64-Bit Server VM (build 13+36-1461, mixed mode, sharing)

[32m       .  [31m _                  _ _       _    [32m__ _ _
[32m      /\\ [31m| | __ ___   ____ _| (_)_ __ | | __[32m\ \ \ \
[32m     ( ( )[31m| |/ _` \ \ / / _` | | | '_ \| |/ /[32m \ \ \ \
[32m      \\/ [31m| | (_| |\ V / (_| | | | | | |   < [32m  ) ) ) )
[32m       '  [31m|_|\__,_| \_/ \__,_|_|_|_| |_|_|\_\[32m / / / /
[0m    =========================================[32m/_/_/_/[0m

	Version:        3.3.2.3
	Build:          1212
	Build time:     02.04.2021 17:37:35 UTC
	Branch          master
	Commit:         7f9925c
	Commit time:    17.02.2021 23:18:16 UTC
	JVM:            13.0
	Lavaplayer      1.3.75

2021-04-19 10:20:46.426  INFO 26334 --- [main] lavalink.server.Launcher                 : Starting Launcher on chip with PID 26334 (/home/vps/chip/lavalink.jar started by vps in /home/vps/chip)
2021-04-19 10:20:46.428  INFO 26334 --- [main] lavalink.server.Launcher                 : No active profile set, falling back to default profiles: default
2021-04-19 10:20:46.919  WARN 26334 --- [background-preinit] o.s.h.c.j.Jackson2ObjectMapperBuilder    : For Jackson Kotlin classes support please add "com.fasterxml.jackson.module:jackson-module-kotlin" to the classpath
2021-04-19 10:20:50.545  WARN 26334 --- [main] io.undertow.websockets.jsr               : UT026010: Buffer pool was not set on WebSocketDeploymentInfo, the default pool will be used
2021-04-19 10:20:50.638  INFO 26334 --- [main] io.undertow.servlet                      : Initializing Spring embedded WebApplicationContext
2021-04-19 10:20:50.639  INFO 26334 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 3998 ms
2021-04-19 10:20:51.676  WARN 26334 --- [main] l.server.config.SentryConfiguration      : Turning off sentry
2021-04-19 10:20:52.834  INFO 26334 --- [main] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring enabled, reporting results every 2 minutes.
2021-04-19 10:20:53.449  INFO 26334 --- [main] lavalink.server.config.KoeConfiguration  : OS: Linux, Arch: amd64
2021-04-19 10:20:53.450  INFO 26334 --- [main] lavalink.server.config.KoeConfiguration  : Enabling JDA-NAS
2021-04-19 10:20:53.466  INFO 26334 --- [main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: loading with filter null
2021-04-19 10:20:53.474  INFO 26334 --- [main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: successfully loaded.
2021-04-19 10:20:54.402  INFO 26334 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2021-04-19 10:20:55.355  INFO 26334 --- [main] org.xnio                                 : XNIO version 3.3.8.Final
2021-04-19 10:20:55.392  INFO 26334 --- [main] org.xnio.nio                             : XNIO NIO Implementation Version 3.3.8.Final
2021-04-19 10:20:55.526  INFO 26334 --- [main] o.s.b.w.e.u.UndertowServletWebServer     : Undertow started on port(s) 2333 (http) with context path ''
2021-04-19 10:20:55.551  INFO 26334 --- [main] lavalink.server.Launcher                 : Started Launcher in 11.759 seconds (JVM running for 13.273)
2021-04-19 10:20:55.556  INFO 26334 --- [main] lavalink.server.Launcher                 : You can safely ignore the big red warning about illegal reflection. See https://github.com/Frederikam/Lavalink/issues/295
2021-04-19 10:21:13.645  INFO 26334 --- [Thread-1] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2021-04-19 10:21:13.650  INFO 26334 --- [Thread-1] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring disabled.
2021-04-19 10:21:32.832  INFO 26359 --- [main] lavalink.server.Launcher                 : 

cloudwithax avatar Apr 19 '21 15:04 cloudwithax

Have you controlled for packet loss between your Discord client and voice servers?

You can also try the dev version, which uses a different library for audio dispatch.

freyacodes avatar Apr 19 '21 15:04 freyacodes

I have tested this, and I can say that this isn't a client-sided issue at all

I tried the dev branch and it is also having the same issue

I don't know if this helps or not, but I had tested jagrosh's bot that uses lavaplayer on the same servers I tested lavalink on and had no issues with playback whatsoever

cloudwithax avatar Apr 19 '21 15:04 cloudwithax

Can you post logs for the dev branch?

Can you also describe the nature of the stuttering/lag? Is it constant or are there breaks?

Are you by any chance setting the volume to more than 100% (overamplifying)?

freyacodes avatar Apr 19 '21 15:04 freyacodes

Heres the dev branch logs

2021-04-15 18:58:03.009  INFO 1227 --- [           main] lavalink.server.Launcher                 : 

[32m       .  [31m _                  _ _       _    [32m__ _ _
[32m      /\\ [31m| | __ ___   ____ _| (_)_ __ | | __[32m\ \ \ \
[32m     ( ( )[31m| |/ _` \ \ / / _` | | | '_ \| |/ /[32m \ \ \ \
[32m      \\/ [31m| | (_| |\ V / (_| | | | | | |   < [32m  ) ) ) )
[32m       '  [31m|_|\__,_| \_/ \__,_|_|_|_| |_|_|\_\[32m / / / /
[0m    =========================================[32m/_/_/_/[0m

	Version:        29fb37958c3514386c58fc62b6099d5c5f59a5ac-SNAPSHOT
	Build:          1215
	Build time:     07.03.2021 15:31:10 UTC
	Branch          dev
	Commit:         29fb379
	Commit time:    07.03.2021 15:28:32 UTC
	JVM:            13
	Lavaplayer      1.3.73

2021-04-15 18:58:03.291  INFO 1227 --- [           main] lavalink.server.Launcher                 : Starting Launcher on chip with PID 1227 (/home/chipbotdiscord/chip/lavalink.jar started by chipbotdiscord in /home/chipbotdiscord/chip)
2021-04-15 18:58:03.293  INFO 1227 --- [           main] lavalink.server.Launcher                 : No active profile set, falling back to default profiles: default
2021-04-15 18:58:03.400  WARN 1227 --- [kground-preinit] o.s.h.c.j.Jackson2ObjectMapperBuilder    : For Jackson Kotlin classes support please add "com.fasterxml.jackson.module:jackson-module-kotlin" to the classpath
2021-04-15 18:58:05.390  WARN 1227 --- [           main] io.undertow.websockets.jsr               : UT026010: Buffer pool was not set on WebSocketDeploymentInfo, the default pool will be used
2021-04-15 18:58:05.429  INFO 1227 --- [           main] io.undertow.servlet                      : Initializing Spring embedded WebApplicationContext
2021-04-15 18:58:05.429  INFO 1227 --- [           main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 2012 ms
2021-04-15 18:58:05.985  WARN 1227 --- [           main] l.server.config.SentryConfiguration      : Turning off sentry
2021-04-15 18:58:06.425  INFO 1227 --- [           main] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring enabled, reporting results every 2 minutes.
2021-04-15 18:58:06.821  INFO 1227 --- [           main] lavalink.server.config.KoeConfiguration  : OS: Linux, Arch: amd64
2021-04-15 18:58:06.823  INFO 1227 --- [           main] lavalink.server.config.KoeConfiguration  : Enabling JDA-NAS
2021-04-15 18:58:06.830  INFO 1227 --- [           main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: loading with filter null
2021-04-15 18:58:06.838  INFO 1227 --- [           main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: successfully loaded.
2021-04-15 18:58:07.323  INFO 1227 --- [           main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2021-04-15 18:58:07.757  INFO 1227 --- [           main] org.xnio                                 : XNIO version 3.3.8.Final
2021-04-15 18:58:07.810  INFO 1227 --- [           main] org.xnio.nio                             : XNIO NIO Implementation Version 3.3.8.Final
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.xnio.nio.NioXnio$2 (jar:file:/home/chipbotdiscord/chip/lavalink.jar!/BOOT-INF/lib/xnio-nio-3.3.8.Final.jar!/) to constructor sun.nio.ch.EPollSelectorProvider()
WARNING: Please consider reporting this to the maintainers of org.xnio.nio.NioXnio$2
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
2021-04-15 18:58:07.929  INFO 1227 --- [           main] o.s.b.w.e.u.UndertowServletWebServer     : Undertow started on port(s) 2333 (http) with context path ''
2021-04-15 18:58:07.936  INFO 1227 --- [           main] lavalink.server.Launcher                 : Started Launcher in 6.311 seconds (JVM running for 7.217)
2021-04-15 18:58:07.939  INFO 1227 --- [           main] lavalink.server.Launcher                 : You can safely ignore the big red warning about illegal reflection. See https://github.com/Frederikam/Lavalink/issues/295
2021-04-15 18:58:25.250  INFO 1227 --- [  XNIO-1 task-1] io.undertow.servlet                      : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-04-15 18:58:25.251  INFO 1227 --- [  XNIO-1 task-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2021-04-15 18:58:25.266  INFO 1227 --- [  XNIO-1 task-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 15 ms
2021-04-15 18:58:25.310  INFO 1227 --- [  XNIO-1 task-1] l.server.io.HandshakeInterceptorImpl     : Incoming connection from /127.0.0.1:60990
2021-04-15 18:58:25.459  INFO 1227 --- [  XNIO-1 task-1] lavalink.server.io.SocketServer          : Connection successfully established
2021-04-15 18:58:25.460  WARN 1227 --- [  XNIO-1 task-1] lavalink.server.io.SocketServer          : Library developers: Please specify a 'Client-Name' header. User agent: Python/3.7 aiohttp/3.7.4.post0
2021-04-15 18:58:29.038  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : Connection closed from /127.0.0.1:60990 -- CloseStatus[code=1006, reason=]
2021-04-15 18:58:29.039  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketContext         : Shutting down 0 playing players.
2021-04-15 18:58:41.097  INFO 1227 --- [  XNIO-1 task-2] l.server.io.HandshakeInterceptorImpl     : Incoming connection from /127.0.0.1:60998
2021-04-15 18:58:41.104  INFO 1227 --- [  XNIO-1 task-2] lavalink.server.io.SocketServer          : Connection successfully established
2021-04-15 18:58:41.105  WARN 1227 --- [  XNIO-1 task-2] lavalink.server.io.SocketServer          : Library developers: Please specify a 'Client-Name' header. User agent: Python/3.7 aiohttp/3.7.4.post0
2021-04-15 18:59:55.461  INFO 1227 --- [  XNIO-1 task-3] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "ytsearch:sesame street joey trap"
2021-04-15 18:59:55.516  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "voiceUpdate", "guildId": "755256992293060670", "sessionId": "e1469e147fdfcc9456e1d1026878dea9", "event": {"token": "0ee05cc2368db905", "guild_id": "755256992293060670", "endpoint": "us-south9042.discord.media:443"}}
2021-04-15 18:59:57.256  INFO 1227 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : Loaded playlist Search results for: sesame street joey trap
2021-04-15 18:59:57.325  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "play", "guildId": "755256992293060670", "track": "QAAAjwIALEpvZXkgVHJhcCAtIFNlc2FtZSBTdHJlZXQgKEV4dGVuZGVkIFZlcnNpb24pAAlKb2V5IFRyYXAAAAAAAAGtsAALV1VIMVRmTVNRS2MAAQAraHR0cHM6Ly93d3cueW91dHViZS5jb20vd2F0Y2g/dj1XVUgxVGZNU1FLYwAHeW91dHViZQAAAAAAAAAA", "noReplace": false, "startTime": "0"}
2021-04-15 19:00:32.046  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "stop", "guildId": "755256992293060670"}
2021-04-15 19:00:32.050  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "destroy", "guildId": "755256992293060670"}
2021-04-15 19:00:38.721  INFO 1227 --- [  XNIO-1 task-5] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "ytsearch:sesame street joey trap"
2021-04-15 19:00:38.790  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "voiceUpdate", "guildId": "755256992293060670", "sessionId": "e1469e147fdfcc9456e1d1026878dea9", "event": {"token": "dac4f994c730fe6c", "guild_id": "755256992293060670", "endpoint": "us-south9042.discord.media:443"}}
2021-04-15 19:00:39.348  INFO 1227 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : Loaded playlist Search results for: sesame street joey trap
2021-04-15 19:00:39.368  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "play", "guildId": "755256992293060670", "track": "QAAAjwIALEpvZXkgVHJhcCAtIFNlc2FtZSBTdHJlZXQgKEV4dGVuZGVkIFZlcnNpb24pAAlKb2V5IFRyYXAAAAAAAAGtsAALV1VIMVRmTVNRS2MAAQAraHR0cHM6Ly93d3cueW91dHViZS5jb20vd2F0Y2g/dj1XVUgxVGZNU1FLYwAHeW91dHViZQAAAAAAAAAA", "noReplace": false, "startTime": "0"}
2021-04-15 19:02:22.981  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "stop", "guildId": "755256992293060670"}
2021-04-15 19:02:22.982  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "destroy", "guildId": "755256992293060670"}
2021-04-15 19:56:54.938  INFO 1227 --- [  XNIO-1 task-7] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "https://youtu.be/hXOFusXmPfg"
2021-04-15 19:56:55.072  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "voiceUpdate", "guildId": "775399277278396416", "sessionId": "e1469e147fdfcc9456e1d1026878dea9", "event": {"token": "ba758287f22a8c48", "guild_id": "775399277278396416", "endpoint": "eu-central5447.discord.media:443"}}
2021-04-15 19:56:55.442  INFO 1227 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : Loaded track I Am The Machine - Dead Cells Animated Trailer
2021-04-15 19:56:55.451  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "play", "guildId": "775399277278396416", "track": "QAAAjwIALkkgQW0gVGhlIE1hY2hpbmUgLSBEZWFkIENlbGxzIEFuaW1hdGVkIFRyYWlsZXIAB1ZhbG1vbnQAAAAAAAOOKAALaFhPRnVzWG1QZmcAAQAraHR0cHM6Ly93d3cueW91dHViZS5jb20vd2F0Y2g/dj1oWE9GdXNYbVBmZwAHeW91dHViZQAAAAAAAAAA", "noReplace": false, "startTime": "0"}
2021-04-15 20:04:43.024  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "stop", "guildId": "775399277278396416"}
2021-04-15 20:04:43.025  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "destroy", "guildId": "775399277278396416"}
2021-04-15 20:31:33.225  INFO 1227 --- [  XNIO-1 task-9] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "ytsearch:sesame street joey trap"
2021-04-15 20:31:33.293  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "voiceUpdate", "guildId": "755256992293060670", "sessionId": "e1469e147fdfcc9456e1d1026878dea9", "event": {"token": "d7953275d86c2d13", "guild_id": "755256992293060670", "endpoint": "us-south8141.discord.media:443"}}
2021-04-15 20:31:33.967  INFO 1227 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : No matches found
2021-04-15 20:31:36.346  INFO 1227 --- [ XNIO-1 task-11] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "ytsearch:sesame street joey trap"
2021-04-15 20:31:36.865  INFO 1227 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : Loaded playlist Search results for: sesame street joey trap
2021-04-15 20:31:36.878  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "play", "guildId": "755256992293060670", "track": "QAAAjwIALEpvZXkgVHJhcCAtIFNlc2FtZSBTdHJlZXQgKEV4dGVuZGVkIFZlcnNpb24pAAlKb2V5IFRyYXAAAAAAAAGtsAALV1VIMVRmTVNRS2MAAQAraHR0cHM6Ly93d3cueW91dHViZS5jb20vd2F0Y2g/dj1XVUgxVGZNU1FLYwAHeW91dHViZQAAAAAAAAAA", "noReplace": false, "startTime": "0"}
2021-04-15 20:35:18.755  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "stop", "guildId": "755256992293060670"}
2021-04-15 20:35:18.756  INFO 1227 --- [   XNIO-1 I/O-2] lavalink.server.io.SocketServer          : {"op": "destroy", "guildId": "755256992293060670"}
2021-04-15 20:37:29.392  INFO 1227 --- [       Thread-1] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2021-04-15 20:37:29.394  INFO 1227 --- [       Thread-1] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring disabled.
2021-04-15 20:37:29.401  INFO 1227 --- [       Thread-1] io.undertow.servlet                      : Destroying Spring FrameworkServlet 'dispatcherServlet'

The lag is constant. It plays the song smoothly for a second and then lags, and does it repetitively. I have a screen recording of the audio from the voice channel. I observed no packet loss from my client whatsoever, and the latency is great as well. Other music bots work fine with no stuttering, laggy playback like I'm experiencing. I have attached a link to the screen recording so you can see what I'm dealing with https://streamable.com/gmjs7p

cloudwithax avatar Apr 19 '21 15:04 cloudwithax

What JVM flags are you running Lavalink with?

freyacodes avatar Apr 19 '21 15:04 freyacodes

java -jar -server -Xms128M -Xmx2G lavalink.jar

cloudwithax avatar Apr 19 '21 15:04 cloudwithax

Try removing the -Xms128M flag

(In general I would also recommend using a newer version of Lavalink)

freyacodes avatar Apr 19 '21 15:04 freyacodes

OK, I ran lavalink using java -jar lavalink.jar and is still producing the same effects

cloudwithax avatar Apr 19 '21 15:04 cloudwithax

Try playing with -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:gc.log and provide the file here

freyacodes avatar Apr 19 '21 15:04 freyacodes

Unrecognized VM option 'PrintGCDateStamps'
Error: Could not create the Java Virtual Machine.
Error: A fatal exception has occurred. Program will exit.

cloudwithax avatar Apr 19 '21 16:04 cloudwithax

Try removing just that flag

freyacodes avatar Apr 19 '21 16:04 freyacodes

heres the output of the gc log

[2.394s][info][gc,heap      ] GC(1) Tenured: 0K->2794K(87424K)
[2.394s][info][gc,metaspace ] GC(1) Metaspace: 6416K->6416K(1056768K)
[2.394s][info][gc           ] GC(1) Pause Young (Allocation Failure) 36M->3M(123M) 12.603ms
[2.394s][info][gc,cpu       ] GC(1) User=0.02s Sys=0.00s Real=0.02s
[2.793s][info][gc,start     ] GC(2) Pause Young (Allocation Failure)
[2.799s][info][gc,heap      ] GC(2) DefNew: 35871K->1291K(39296K)
[2.799s][info][gc,heap      ] GC(2) Tenured: 2794K->2794K(87424K)
[2.799s][info][gc,metaspace ] GC(2) Metaspace: 8198K->8198K(1058816K)
[2.799s][info][gc           ] GC(2) Pause Young (Allocation Failure) 37M->3M(123M) 6.096ms
[2.799s][info][gc,cpu       ] GC(2) User=0.01s Sys=0.00s Real=0.00s
[3.297s][info][gc,start     ] GC(3) Pause Young (Allocation Failure)
[3.305s][info][gc,heap      ] GC(3) DefNew: 36235K->1868K(39296K)
[3.305s][info][gc,heap      ] GC(3) Tenured: 2794K->2794K(87424K)
[3.305s][info][gc,metaspace ] GC(3) Metaspace: 9849K->9849K(1058816K)
[3.305s][info][gc           ] GC(3) Pause Young (Allocation Failure) 38M->4M(123M) 7.842ms
[3.305s][info][gc,cpu       ] GC(3) User=0.01s Sys=0.00s Real=0.01s
[3.910s][info][gc,start     ] GC(4) Pause Young (Allocation Failure)
[3.919s][info][gc,heap      ] GC(4) DefNew: 36812K->2629K(39296K)
[3.919s][info][gc,heap      ] GC(4) Tenured: 2794K->2794K(87424K)
[3.919s][info][gc,metaspace ] GC(4) Metaspace: 13174K->13174K(1060864K)
[3.919s][info][gc           ] GC(4) Pause Young (Allocation Failure) 38M->5M(123M) 8.633ms
[3.919s][info][gc,cpu       ] GC(4) User=0.01s Sys=0.00s Real=0.01s
[4.456s][info][gc,start     ] GC(5) Pause Young (Allocation Failure)
[4.466s][info][gc,heap      ] GC(5) DefNew: 37573K->2264K(39296K)
[4.466s][info][gc,heap      ] GC(5) Tenured: 2794K->3525K(87424K)
[4.466s][info][gc,metaspace ] GC(5) Metaspace: 16556K->16556K(1064960K)
[4.466s][info][gc           ] GC(5) Pause Young (Allocation Failure) 39M->5M(123M) 10.227ms
[4.466s][info][gc,cpu       ] GC(5) User=0.01s Sys=0.00s Real=0.01s
[5.573s][info][gc,start     ] GC(6) Pause Young (Allocation Failure)
[5.589s][info][gc,heap      ] GC(6) DefNew: 37208K->3571K(39296K)
[5.589s][info][gc,heap      ] GC(6) Tenured: 3525K->3901K(87424K)
[5.589s][info][gc,metaspace ] GC(6) Metaspace: 18858K->18858K(1067008K)
[5.589s][info][gc           ] GC(6) Pause Young (Allocation Failure) 39M->7M(123M) 16.316ms
[5.589s][info][gc,cpu       ] GC(6) User=0.02s Sys=0.00s Real=0.01s
[6.148s][info][gc,start     ] GC(7) Pause Young (Allocation Failure)
[6.161s][info][gc,heap      ] GC(7) DefNew: 38515K->2569K(39296K)
[6.161s][info][gc,heap      ] GC(7) Tenured: 3901K->5666K(87424K)
[6.161s][info][gc,metaspace ] GC(7) Metaspace: 19702K->19702K(1067008K)
[6.161s][info][gc           ] GC(7) Pause Young (Allocation Failure) 41M->8M(123M) 13.227ms
[6.161s][info][gc,cpu       ] GC(7) User=0.02s Sys=0.00s Real=0.01s
[6.598s][info][gc,start     ] GC(8) Pause Full (Metadata GC Threshold)
[6.598s][info][gc,phases,start] GC(8) Phase 1: Mark live objects
[6.618s][info][gc,phases      ] GC(8) Phase 1: Mark live objects 19.412ms
[6.618s][info][gc,phases,start] GC(8) Phase 2: Compute new object addresses
[6.624s][info][gc,phases      ] GC(8) Phase 2: Compute new object addresses 6.276ms
[6.624s][info][gc,phases,start] GC(8) Phase 3: Adjust pointers
[6.635s][info][gc,phases      ] GC(8) Phase 3: Adjust pointers 10.914ms
[6.635s][info][gc,phases,start] GC(8) Phase 4: Move objects
[6.637s][info][gc,phases      ] GC(8) Phase 4: Move objects 2.074ms
[6.637s][info][gc,heap        ] GC(8) DefNew: 19369K->0K(39424K)
[6.637s][info][gc,heap        ] GC(8) Tenured: 5666K->8704K(87424K)
[6.637s][info][gc,metaspace   ] GC(8) Metaspace: 20535K->20535K(1067008K)
[6.637s][info][gc             ] GC(8) Pause Full (Metadata GC Threshold) 24M->8M(123M) 39.369ms
[6.637s][info][gc,cpu         ] GC(8) User=0.04s Sys=0.00s Real=0.04s
[7.734s][info][gc,start       ] GC(9) Pause Young (Allocation Failure)
[7.741s][info][gc,heap        ] GC(9) DefNew: 35072K->1233K(39424K)
[7.741s][info][gc,heap        ] GC(9) Tenured: 8704K->8704K(87424K)
[7.741s][info][gc,metaspace   ] GC(9) Metaspace: 22956K->22956K(1071104K)
[7.741s][info][gc             ] GC(9) Pause Young (Allocation Failure) 42M->9M(123M) 6.919ms
[7.741s][info][gc,cpu         ] GC(9) User=0.01s Sys=0.00s Real=0.00s
[8.765s][info][gc,start       ] GC(10) Pause Young (Allocation Failure)
[8.785s][info][gc,heap        ] GC(10) DefNew: 36305K->2260K(39424K)
[8.785s][info][gc,heap        ] GC(10) Tenured: 8704K->8704K(87424K)
[8.785s][info][gc,metaspace   ] GC(10) Metaspace: 25593K->25593K(1073152K)
[8.785s][info][gc             ] GC(10) Pause Young (Allocation Failure) 43M->10M(123M) 20.004ms
[8.785s][info][gc,cpu         ] GC(10) User=0.02s Sys=0.00s Real=0.02s
[9.661s][info][gc,start       ] GC(11) Pause Young (Allocation Failure)
[9.687s][info][gc,heap        ] GC(11) DefNew: 37332K->1967K(39424K)
[9.687s][info][gc,heap        ] GC(11) Tenured: 8704K->9853K(87424K)
[9.687s][info][gc,metaspace   ] GC(11) Metaspace: 30011K->30011K(1077248K)
[9.687s][info][gc             ] GC(11) Pause Young (Allocation Failure) 44M->11M(123M) 26.187ms
[9.687s][info][gc,cpu         ] GC(11) User=0.02s Sys=0.01s Real=0.03s
[10.737s][info][gc,start       ] GC(12) Pause Full (Metadata GC Threshold)
[10.737s][info][gc,phases,start] GC(12) Phase 1: Mark live objects
[10.771s][info][gc,phases      ] GC(12) Phase 1: Mark live objects 33.516ms
[10.771s][info][gc,phases,start] GC(12) Phase 2: Compute new object addresses
[10.781s][info][gc,phases      ] GC(12) Phase 2: Compute new object addresses 9.924ms
[10.781s][info][gc,phases,start] GC(12) Phase 3: Adjust pointers
[10.800s][info][gc,phases      ] GC(12) Phase 3: Adjust pointers 19.219ms
[10.800s][info][gc,phases,start] GC(12) Phase 4: Move objects
[10.803s][info][gc,phases      ] GC(12) Phase 4: Move objects 2.918ms
[10.803s][info][gc,heap        ] GC(12) DefNew: 26787K->0K(39424K)
[10.803s][info][gc,heap        ] GC(12) Tenured: 9853K->13317K(87424K)
[10.803s][info][gc,metaspace   ] GC(12) Metaspace: 34198K->34198K(1079296K)
[10.803s][info][gc             ] GC(12) Pause Full (Metadata GC Threshold) 35M->13M(123M) 66.469ms
[10.803s][info][gc,cpu         ] GC(12) User=0.07s Sys=0.00s Real=0.06s
[11.690s][info][gc,start       ] GC(13) Pause Young (Allocation Failure)
[11.702s][info][gc,heap        ] GC(13) DefNew: 35072K->1298K(39424K)
[11.702s][info][gc,heap        ] GC(13) Tenured: 13317K->13317K(87424K)
[11.702s][info][gc,metaspace   ] GC(13) Metaspace: 37395K->37395K(1083392K)
[11.702s][info][gc             ] GC(13) Pause Young (Allocation Failure) 47M->14M(123M) 12.231ms
[11.702s][info][gc,cpu         ] GC(13) User=0.02s Sys=0.00s Real=0.01s
[12.760s][info][gc,start       ] GC(14) Pause Young (Allocation Failure)
[12.772s][info][gc,heap        ] GC(14) DefNew: 36370K->2920K(39424K)
[12.772s][info][gc,heap        ] GC(14) Tenured: 13317K->13317K(87424K)
[12.772s][info][gc,metaspace   ] GC(14) Metaspace: 40051K->40051K(1085440K)
[12.772s][info][gc             ] GC(14) Pause Young (Allocation Failure) 48M->15M(123M) 11.351ms
[12.772s][info][gc,cpu         ] GC(14) User=0.01s Sys=0.00s Real=0.01s
[38.305s][info][gc,start       ] GC(15) Pause Young (Allocation Failure)
[38.332s][info][gc,heap        ] GC(15) DefNew: 37992K->2559K(39424K)
[38.332s][info][gc,heap        ] GC(15) Tenured: 13317K->14465K(87424K)
[38.332s][info][gc,metaspace   ] GC(15) Metaspace: 43143K->43143K(1087488K)
[38.332s][info][gc             ] GC(15) Pause Young (Allocation Failure) 50M->16M(123M) 26.952ms
[38.332s][info][gc,cpu         ] GC(15) User=0.03s Sys=0.00s Real=0.02s
[45.890s][info][gc,start       ] GC(16) Pause Young (Allocation Failure)
[45.909s][info][gc,heap        ] GC(16) DefNew: 37631K->2594K(39424K)
[45.909s][info][gc,heap        ] GC(16) Tenured: 14465K->15958K(87424K)
[45.909s][info][gc,metaspace   ] GC(16) Metaspace: 46521K->46521K(1091584K)
[45.909s][info][gc             ] GC(16) Pause Young (Allocation Failure) 50M->18M(123M) 18.360ms
[45.909s][info][gc,cpu         ] GC(16) User=0.01s Sys=0.00s Real=0.02s
[46.640s][info][gc,start       ] GC(17) Pause Young (Allocation Failure)
[46.655s][info][gc,heap        ] GC(17) DefNew: 27186K->3016K(39424K)
[46.655s][info][gc,heap        ] GC(17) Tenured: 15958K->16964K(87424K)
[46.655s][info][gc,metaspace   ] GC(17) Metaspace: 51889K->51889K(1095680K)
[46.655s][info][gc             ] GC(17) Pause Young (Allocation Failure) 42M->19M(123M) 14.429ms
[46.655s][info][gc,cpu         ] GC(17) User=0.01s Sys=0.00s Real=0.02s
[47.820s][info][gc,start       ] GC(18) Pause Young (Allocation Failure)
[47.841s][info][gc,heap        ] GC(18) DefNew: 37860K->3293K(39424K)
[47.841s][info][gc,heap        ] GC(18) Tenured: 16964K->34839K(87424K)
[47.841s][info][gc,metaspace   ] GC(18) Metaspace: 53423K->53423K(1097728K)
[47.841s][info][gc             ] GC(18) Pause Young (Allocation Failure) 53M->37M(123M) 20.393ms
[47.841s][info][gc,cpu         ] GC(18) User=0.02s Sys=0.00s Real=0.02s
[49.365s][info][gc,start       ] GC(19) Pause Young (Allocation Failure)
[49.382s][info][gc,heap        ] GC(19) DefNew: 38363K->1354K(39424K)
[49.382s][info][gc,heap        ] GC(19) Tenured: 34839K->52633K(87424K)
[49.382s][info][gc,metaspace   ] GC(19) Metaspace: 53993K->53993K(1097728K)
[49.382s][info][gc             ] GC(19) Pause Young (Allocation Failure) 71M->52M(123M) 17.170ms
[49.382s][info][gc,cpu         ] GC(19) User=0.01s Sys=0.01s Real=0.01s

cloudwithax avatar Apr 19 '21 16:04 cloudwithax

I think we can rule out GC pauses, though I have no idea what is causing your problem.

It also doesn't appear to be a network issue judging by the sound.

freyacodes avatar Apr 19 '21 16:04 freyacodes

Would it have anything to do with JVM itself?

cloudwithax avatar Apr 19 '21 16:04 cloudwithax

Seems unlikely now that we have ruled out the GC.

You could try Zulu 13, which is what the Docker image uses.

freyacodes avatar Apr 19 '21 16:04 freyacodes

still the same issue with zulu 13

cloudwithax avatar Apr 19 '21 16:04 cloudwithax

i had also noticed that someone else had the same issue but then closed the issue as well https://github.com/freyacodes/Lavalink/issues/471

cloudwithax avatar Apr 19 '21 17:04 cloudwithax

For me Lavalink also stutters constantly in short period (<= 1 sec). It doesn't break the sound like in the streamable of cloudwithax, but it stutters a bit and produces weird noise distortion everytime.

Tested with my previous server and now with a new server. Bandwidth is good, speedtest shows 327 Mbit/s download and 318 Mbit/s upload. Htop shows 2% cpu usage.

EDIT: Seems like the voice region has been the issue for me. Changing from Europe to another region fixes the stuttering for me.

emre1702 avatar Apr 27 '21 15:04 emre1702

I have the same issue, i tested on DigitalOcean, OVH and Contabo hosting everywhere songs stutter in between. I have latest version of lavalink, running on java 13 on ubuntu, I tried changing region but no luck. I wonder how big bot use this and still produce good quality music output

arpanr avatar Jun 10 '21 17:06 arpanr

I’m closing this issue because I have already found a fix to this issue. Java 13 seems to act weird with Lavalink. The solution is to use anything above Java 15 oddly enough. No sound issues at all since I switched.

cloudwithax avatar Jun 10 '21 18:06 cloudwithax

Same problem with Java 17.

JellyBrick avatar Oct 02 '21 12:10 JellyBrick

Also happening to me with Java 15, I suggest reopening this issue.

Visne avatar Oct 12 '21 02:10 Visne

Same problem with Java 17...

leopatik avatar Dec 14 '21 21:12 leopatik

yes really reopen this

pauldb09 avatar Feb 17 '22 19:02 pauldb09

Any news on this ? I can do all sorts of tests if needed.

Running on k3s here. Symetrical gigabit fiber, 8ms latency with our nearest Montreal Discord voice server.

samuelleb11 avatar Jun 22 '22 20:06 samuelleb11

  • Check your buffer durations in your application.yml. default NAS is 400ms and default frame buffer is 5000ms.
  • Test alternative Discord voice channel regions throughout the day to rule out overloaded voice servers.
  • Test a different media source to rule out buffering issues at the source input.
  • Check your JVM arguments and make sure you haven't incorrectly configured something that could be leading to reduced performance.
  • If hosting on ARM, you should really favour x86-64 for overall better performance, compatibility and support.
  • Test on another (different) server altogether if you can, to rule out an issue with networking/routing and hardware/overprovisioning (only really applicable to VPS').

devoxin avatar Jun 22 '22 22:06 devoxin

There hasn't been any new reports/feedback on this issue so I'm gonna close this. Try updating to new newest lavalink version v3.6.1 as of writing this and if this issue persists feel free to reopen the issue

topi314 avatar Oct 31 '22 10:10 topi314