Excessive memory usage when parsing large registry data

Vedabahu commented 2 months ago

Ludusavi version

v0.24.3

Operating system

Windows

Installation method

Scoop

Description

It says :

ludusavi backup --preview
Scan (00:00:58) ██████████████████████████████████████████████████████████████████████████████████░ Games: 47656 / 47686
memory allocation of 15032385536 bytes failed

I don't think it is supposed to allocate 14 GB of memory....

Logs

Logs:

[2024-07-18T19:06:35.878Z] WARN [ludusavi::resource::config] Unable to locate Steam directory: FailedLocate(Backend(BackendError { inner: BackendErrorInner(Os { code: 2, kind: NotFound, message: "The system cannot find the file specified." }) }))
[2024-07-18T19:07:14.202Z] WARN [ludusavi::scan::steam] Unable to locate Steam directory: FailedLocate(Backend(BackendError { inner: BackendErrorInner(Os { code: 2, kind: NotFound, message: "The system cannot find the file specified." }) }))
[2024-07-18T19:07:14.219Z] WARN [ludusavi::scan::launchers::heroic::gog] Unable to parse library in StrictPath { raw: "C:/Users/veda/AppData/Roaming/heroic/store_cache/gog_library.json", basis: None }: missing field `games` at line 1 column 2
[2024-07-18T19:07:48.770Z] WARN [ludusavi::scan::steam] Unable to locate Steam directory: FailedLocate(Backend(BackendError { inner: BackendErrorInner(Os { code: 2, kind: NotFound, message: "The system cannot find the file specified." }) }))
[2024-07-18T19:07:48.771Z] WARN [ludusavi::scan::launchers::heroic::gog] Unable to parse library in StrictPath { raw: "C:/Users/veda/AppData/Roaming/heroic/store_cache/gog_library.json", basis: None }: missing field `games` at line 1 column 2

Command run:

mtkennerly commented 2 months ago

Hi! Could you try running it again with the RUST_LOG environment variable set to ludusavi=trace, and then send me the log files? That would help narrow down if there's a specific game that's trying to back up way too much. I'm not able to reproduce this locally, so I may not have the right game to trigger it.

mtkennerly commented 2 months ago

Also, was this working previously for you? If so, do you know the timeframe between when it was working and when the error started?

Vedabahu commented 2 months ago

Hi! Could you try running it again with the RUST_LOG environment variable set to ludusavi=trace, and then send me the log files? That would help narrow down if there's a specific game that's trying to back up way too much. I'm not able to reproduce this locally, so I may not have the right game to trigger it.

Here you go

Github Gist link

ludusavi_rCURRENT.log

Vedabahu commented 2 months ago

Also, was this working previously for you? If so, do you know the timeframe between when it was working and when the error started?

Yes, it was working before. It started on 19-07-2024. All of the backups before that were working properly. After it failed once, I updated ludusavi to 0.24.3. thinking that it would solve the problem but the problem persisted.

mtkennerly commented 2 months ago

Here you go

It looks like you may have set ludusavi=debug rather than ludusavi=trace. Could you provide trace logs as well please?

Vedabahu commented 2 months ago

Here you go

It looks like you may have set ludusavi=debug rather than ludusavi=trace. Could you provide trace logs as well please?

Oh, my bad. Here you go:

Github gist: trace logs

ludusavi_rCURRENT.log

mtkennerly commented 2 months ago

Thanks! I'm not sure of the cause yet, but I do see a couple of interesting things:

The last game being scanned is Nine Sols
There is a 20 second gap before the first Nine Sols log message

Could you try with this build as well?

ludusavi-v0.24.3-post.5+09b89c7-win64.zip

I've made a few tweaks to help narrow down the issue:

Enabled trace logging by default
Removed the size/rotation limits on the log file
Made it only scan one game at a time (so the log flow is easier to follow)
Made logging synchronous (in case we were missing some log messages right before the crash)

The scan will be much slower (took 1.5 minutes on my system), but it should be easier to tell exactly where it fails and if Nine Sols still has a gap beforehand. Also, the log file will be rather huge, but zipping helps 😅 (125 MB -> 6 MB for me).

Vedabahu commented 2 months ago

It gave me the same error as before.

Here are the logs

ludusavi-temp_2024-07-19_16-04-51.zip

mtkennerly commented 2 months ago

Okay, it's 100% related to Nine Sols. How large are your existing backups of it? It looks like it took 30 seconds just to load the most recent backup for that game. Would you mind sending me a copy of your Nine Sols backups so I can check them out? (unless they're multi-GB, then just the mapping.yaml should be enough)

Vedabahu commented 2 months ago

Here you go. These are the last 2 backups.... and the mapping.yaml file is for the newer backup.

One thing that I noticed is that the size of the registry.yaml file changed drastically from the old backup to the new backup. It went from 363KB to 108MB.

Old backup:

New Backup:

In both cases, the overall zip file that was uploaded to g-drive still remained around 6MB.

I have zipped it because Github does not allow me to upload yaml files here.

nineSols-backup.zip

mtkennerly commented 2 months ago

Thanks, it does look like the memory usage is ballooning when Ludusavi parses that registry.yaml. I see it spiking by ~1 GB in Task Manager. I'll try to find out if we can reduce that or at least put a safeguard limit on the registry data.

In the meantime, I've updated the manifest (https://github.com/mtkennerly/ludusavi-manifest/commit/9d0d0d243568a97136c5a144e76abc8a91382709) to ignore the registry for Nine Sols. I recommend deleting the Nine Sols backup folder and just making a new backup. You can use the refresh button on the "other" screen to force it to download the updated manifest right away.

mtkennerly / ludusavi