Long update download

[tr1kright]

Bug description

I do not know if this should happen by default, but downloading one mod from the update from my modpack took about 5 minutes. I can't figure out at what stage the slowdown begins, maybe it's related to the connection.

Part of the log

[19:18:57] [Netty Client IO #0] [AutoModpack/INFO]: Versions match 4.0.2

[19:18:57] [Netty Client IO #0] [AutoModpack/INFO]: Modpack address: desktop-dqce3a3:25565 Requires to follow magic protocol: true

[19:18:58] [Netty Client IO #0] [AutoModpack/INFO]: Indexing file system...

[19:19:00] [Netty Client IO #0] [AutoModpack/INFO]: Verifying content against server list...

[19:19:42] [ForkJoinPool.commonPool-worker-4] [AutoModpack/INFO]: Missing file: /mods/wither_spawn_animation-1.6-forge-1.20.1.jar

[19:19:49] [Netty Client IO #0] [AutoModpack/INFO]: Indexing file system...

[19:19:49] [Netty Client IO #0] [AutoModpack/INFO]: Verifying content against server list...

[19:19:50] [ForkJoinPool.commonPool-worker-8] [AutoModpack/INFO]: Missing file: /mods/wither_spawn_animation-1.6-forge-1.20.1.jar

[19:19:52] [Netty Client IO #0] [AutoModpack/WARN]: Modpack update found

[19:20:05] [Netty Client IO #0] [AutoModpack/INFO]: Skipped 15044 editable files

[19:20:05] [Netty Client IO #0] [AutoModpack/INFO]: Skipped 957 already downloaded files

[19:20:06] [Netty Client IO #0] [AutoModpack/INFO]: Finished fetching urls in 1011ms

[19:20:06] [Netty Client IO #0] [AutoModpack/INFO]: In queue left 1 files to download (1MB)

[19:20:06] [AutoModpackDownload-1] [AutoModpack/INFO]: Downloading wither_spawn_animation-1.6-forge-1.20.1.jar - [https://edge.forgecdn.net/files/7392/205/wither_spawn_animation-1.6-forge-1.20.1.jar, https://cdn.modrinth.com/data/Vr6UqBIT/versions/tNuLm8Ub/wither_spawn_animation-1.6-forge-1.20.1.jar]

[19:20:06] [AutoModpackDownload-1] [AutoModpack/INFO]: Downloading from https://edge.forgecdn.net/files/7392/205/wither_spawn_animation-1.6-forge-1.20.1.jar

[19:20:07] [AutoModpackDownload-1] [AutoModpack/INFO]: Successfully downloaded wither_spawn_animation-1.6-forge-1.20.1.jar from https://edge.forgecdn.net/files/7392/205/wither_spawn_animation-1.6-forge-1.20.1.jar

[19:20:07] [Netty Client IO #0] [AutoModpack/INFO]: Finished downloading files in 2329ms

[19:20:07] [Netty Client IO #0] [AutoModpack/INFO]: Done, saving automodpack\modpacks\Trikcraft\automodpack-content.json

[19:20:33] [Netty Client IO #0] [AutoModpack/INFO]: Deleting automodpack\modpacks\Trikcraft\mods\wither_spawn_animation-1.5.2-forge-1.20.1.jar

[19:24:15] [Netty Client IO #0] [AutoModpack/INFO]: Update completed! Required restart: false Took: 263066ms

Steps to reproduce

1. Join a server with an older version of the modpack

Expected behavior

I imagined that it would take much less time, like 1 minute or less.

Actual behavior

No response

Relevant logs

https://mclo.gs/avTx8G5

Minecraft & Mod Loader versions

1.20.1 Forge 47.4.13

Minecraft launcher

Modrinth Launcher

Operating system

Windows 10

AutoModpack version

4.0.2

Other information

No response

Check list

• [x] I have verified that the issue persists in the latest version of the mod.
• [x] I have searched the existing issues and confirmed that this is not a duplicate.
• [x] I have provided all the necessary information to reproduce the issue.
• [ ] I have verified that the issue does not occur without the AutoModpack - Ignore if you are reporting a mod conflict issue.

[Skidamek]

Hmm it looks like you have a lot of files, could you share your modpack-content.json?

[tr1kright]

automodpack-content.json

[tr1kright]

could the lack of a SSD affect the download speed or something like that?

[Skidamek]

Thanks, yeah it could since looking at the logs the actual download took just 2 sec, the whole process takes much more because it first checks which files changed and what do we need to download. That being said, in this case it's ridiculous. I will look into optimization of this code path.

[Skidamek]

Okay so, the bottleneck here was definitely the disk I/O. To minimize it I've implemented a simple metadata cache whose the whole purpose is to store already calculated sha1 hashes for downloaded files and use them later for all the logic if the size and modification date of the file matches, that should mean that any subsequent modpack update should be basically instant compared to the 4mins of busy waiting.

@tr1kright Please test this build from github actions and share your results! https://github.com/Skidamek/AutoModpack/actions/runs/20637383238/artifacts/5002685282

[tr1kright]

ok, I'll test it later

[tr1kright]

Well, the mod loading is almost instant, but it still takes a long time to remove the previous mod version (i guess) https://mclo.gs/qt2auCi

[Skidamek]

try relaunching the game again, the first time could be slower because it still had to calculate all the hashes to save them into cache and then it can use them to be faster

[Skidamek]

oh wait, i see whats bottlenecking now

[Skidamek]

try now https://github.com/Skidamek/AutoModpack/actions/runs/20639320070/artifacts/5003157015

[tr1kright]

The problem still remained, although deleting the file was a little faster this time. https://mclo.gs/mPwlfqD

[Skidamek]

Okay, please try this https://github.com/Skidamek/AutoModpack/actions/runs/20640673795/artifacts/5003464283

[tr1kright]

Still the same, but even faster https://mclo.gs/yKNA2jJ

[tr1kright]

Now it took 144903ms

[tr1kright]

Maybe there's something else I can do for more information?

[Skidamek]

damn it thats still a lot, atleast we cut the time in half...

[Skidamek]

i think i would need to rewrite whole dependency sorting code - since that's the part which makes the game hang for 2 mins right now (its a complete mess... i don't even really comprehend what's happening there) - and fix #247 before that to make this as fast as it should be

[Skidamek]

however what confuses me is why does indexing file system is quick on preload but it takes 20sec while in game....

[19:10:56] [main] [AutoModpack/INFO]: Indexing file system...
[19:10:58] [main] [AutoModpack/INFO]: Verifying content against server list...

[19:25:44] [Netty Client IO #0] [AutoModpack/INFO]: Indexing file system...
[19:26:04] [Netty Client IO #0] [AutoModpack/INFO]: Verifying content against server list...

https://github.com/Skidamek/AutoModpack/blob/8cf9a9f0a1eced73c6996aac5cbe9c7884428ea5/loader/core/src/main/java/pl/skidam/automodpack_loader_core/client/ModpackUtils.java#L50-L61

[tr1kright]

however what confuses me is why does indexing file system is quick on preload but it takes 20sec while in game....

Most likely, this is due to the fact that the server and client are running on my PC despite the fact that I have only 16 GB of RAM and there may not be enough memory, which is why the swap file is involved. And in general, I have quite average components, so this may be a problem on my side.