Restarting download crashes with "file locked by another process"

Question

Restarting download crashes with "file locked by another process"

waltersamson opened this issue 3 years ago · 6 comments

1.16.4 forge

Summary:
After stopping download, starting download again would sometimes trigger a crash.
The error is: java.io.IOException: The process cannot access the file because another process has locked a portion of the file

Steps to reproduce:

Prepare an instance of minecraft 1.16.4 installation, install the forge version of WDL
Join a server, start downloading (Multiworld setting doesn't matter)
Stop downloading
Wait for a while (up to 20 minutes), click "Download this world" or the triple dot settings button
A screen with text "Saving world" is shown, then it crashes.
If it doesn't crash, repeat step 3-4, remember not to restart too quickly after stopping.

Log: https://paste.debian.net/plain/1204547/

The screen at the time of crashing:

Note that in step 4, sufficient amount of time (up to 20 minutes) has passed before starting the download again.

I've used 1.12.2 liteloader version for a long time without encountering this issue.

Thanks!

Answer 1 · 2021-07-16T17:54:44.000Z

According to that log, the first save completed successfully:

[14:49:37] [Render thread/INFO] [minecraft/NewChatGui]: [CHAT] [WorldDL] Save complete. Your single player file is ready to play!

Then it crashed ~10 seconds later:

[14:49:48] [Render thread/FATAL] [minecraft/Minecraft]: Reported exception thrown!

net.minecraft.crash.ReportedException: mouseClicked event handler
	-snip-
Caused by: java.lang.RuntimeException: WorldDownloader: Couldn't create saveHandler for saving the world!
	at wdl.WDL.startDownload(WDL.java:429) ~[wdl:?] {re:classloading}
	at wdl.WDLEvents$HooksListener$StartDownloadButton.performAction(WDLEvents.java:878) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.ExtButton.func_230930_b_(ExtButton_1_16.java:51) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.WDLButton.func_230930_b_(WDLButton.java:21) ~[wdl:?] {re:classloading}
	at net.minecraft.client.gui.widget.button.AbstractButton.func_230982_a_(SourceFile:16) ~[?:?] {re:classloading}
	at net.minecraft.client.gui.widget.Widget.func_231044_a_(Widget.java:136) ~[?:?] {re:classloading,pl:runtimedistcleaner:A,re:mixin,pl:runtimedistcleaner:A}
	at wdl.gui.widget.ExtButton.func_231044_a_(ExtButton_1_16.java:59) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.WDLButton.func_231044_a_(WDLButton.java:21) ~[wdl:?] {re:classloading}
	at net.minecraft.client.gui.INestedGuiEventHandler.func_231044_a_(SourceFile:27) ~[?:?] {re:classloading,re:mixin}
	at net.minecraft.client.MouseHelper.lambda$mouseButtonCallback$0(MouseHelper.java:87) ~[?:?] {re:classloading,pl:runtimedistcleaner:A}
	at net.minecraft.client.gui.screen.Screen.func_231153_a_(Screen.java:427) ~[?:?] {re:classloading,pl:runtimedistcleaner:A,re:mixin,pl:runtimedistcleaner:A}
	... 22 more
Caused by: java.io.IOException: The process cannot access the file because another process has locked a portion of the file
	at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[?:1.8.0_201] {}
	at sun.nio.ch.FileDispatcherImpl.write(Unknown Source) ~[?:1.8.0_201] {}
	at sun.nio.ch.IOUtil.writeFromNativeBuffer(Unknown Source) ~[?:1.8.0_201] {}
	at sun.nio.ch.IOUtil.write(Unknown Source) ~[?:1.8.0_201] {}
	at sun.nio.ch.FileChannelImpl.write(Unknown Source) ~[?:1.8.0_201] {}
	at net.minecraft.server.SessionLockManager.func_232998_a_(SourceFile:40) ~[?:?] {re:classloading}
	at net.minecraft.world.storage.SaveFormat$LevelSave.<init>(SaveFormat.java:277) ~[?:?] {re:computing_frames,re:classloading}
	at net.minecraft.world.storage.SaveFormat.func_237274_c_(SaveFormat.java:265) ~[?:?] {re:classloading}
	at wdl.versioned.HandlerFunctions.getSaveHandler(Handlers_1_16_2.java:206) ~[wdl:?] {re:classloading}
	at wdl.versioned.VersionedFunctions.getSaveHandler(VersionedFunctions.java:164) ~[wdl:?] {re:classloading}
	at wdl.WDL.startDownload(WDL.java:427) ~[wdl:?] {re:classloading}
	at wdl.WDLEvents$HooksListener$StartDownloadButton.performAction(WDLEvents.java:878) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.ExtButton.func_230930_b_(ExtButton_1_16.java:51) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.WDLButton.func_230930_b_(WDLButton.java:21) ~[wdl:?] {re:classloading}
	at net.minecraft.client.gui.widget.button.AbstractButton.func_230982_a_(SourceFile:16) ~[?:?] {re:classloading}
	at net.minecraft.client.gui.widget.Widget.func_231044_a_(Widget.java:136) ~[?:?] {re:classloading,pl:runtimedistcleaner:A,re:mixin,pl:runtimedistcleaner:A}
	at wdl.gui.widget.ExtButton.func_231044_a_(ExtButton_1_16.java:59) ~[wdl:?] {re:classloading}
	at wdl.gui.widget.WDLButton.func_231044_a_(WDLButton.java:21) ~[wdl:?] {re:classloading}
	at net.minecraft.client.gui.INestedGuiEventHandler.func_231044_a_(SourceFile:27) ~[?:?] {re:classloading,re:mixin}
	at net.minecraft.client.MouseHelper.lambda$mouseButtonCallback$0(MouseHelper.java:87) ~[?:?] {re:classloading,pl:runtimedistcleaner:A}
	at net.minecraft.client.gui.screen.Screen.func_231153_a_(Screen.java:427) ~[?:?] {re:classloading,pl:runtimedistcleaner:A,re:mixin,pl:runtimedistcleaner:A}
	... 22 more

I assume this was just your first test, and you tried waiting 20 minutes a later time with the same result.

The one other thing I see is that you have multiworld support disabled (isMultiworld: false and LinkedWorlds: ). Since the save file is opened at a different time when multiworld support is enabled or disabled, that may be relevant (but it also may be a bug with the forge version that always happens).

Answer 2 · 2021-07-17T02:58:10.000Z

Hi, thanks for the quick response!

Sorry I wasn't being 100% consistent with my reproduce steps and the logfile. In that logfile I didn't wait for 20 minutes, but just ~10 seconds. However I did have experienced crash with a long delay between stopping and starting download.

So yes, the line "[FATAL] [ne.mi.co.ForgeMod/]: Preparing crash report with UUID .... " is the first log item after clicking "Download this world" to restart.

Also I've missed an item in my steps to reproduce: Disabling world backups. After more testing I found that world backup setting could be related.

So far I've been unable to trigger the crash with the default setting "Zip a copy of the world". And it crashes (almost) consistently with "No backup".

Thanks!

Answer 3 · 2021-07-17T03:23:55.000Z

Here is the log from 1.16.4 base edit version, without all the forge stuff, and the behavior is the same:

With disabled world backups:

https://paste.debian.net/plain/1204637/

Regarding multiworld setting, I didn't quite understand, since I just use the default option (Disabled) at first start.

Thanks!

Answer 4 · 2021-07-23T20:48:16.000Z

I've figured out the cause: I only closed the saveHandler (here) if backupType is not NONE; closing the saveHandler is what releases the lock on session.lock, so if that wasn't done the game is unable to get a new lock and thus crashes. This will be fixed in the next update (whenever that is; hopefully soon).

Answer 5 · 2021-07-26T04:15:02.000Z

I've been trying to read the code to investigate myself for the last few days, and you beat me to it!

Thank you very much!

Meanwhile I'm now using the following workaround: Set backup mode to a custom command that creates a fake file (must be larger than 128 bytes), since the actual backup can be quite slow as the saved world get large.

Answer 6 · 2021-07-26T04:37:38.000Z

Oh, one other thing to note: you should be able to press esc while a backup is occurring to skip the backup step. (This isn't clearly indicated anywhere, though.)