'zip file closed' when stopping server too quickly

Question

'zip file closed' when stopping server too quickly

nathanfranke opened this issue 3 years ago · 6 comments

nathanfranke commented 3 years ago

Latest Reproducible:
EssentialsX-2.19.4-dev+2-3984bdd
paper-1.18.2-235

Type of bug

Error in console

`/ess dump all` output

https://essentialsx.net/dump.html?id=fc64f23abdcb4c2795426d752a39a199

Error log (if applicable)

https://gist.github.com/nathanfranke/8db8c5d6d4272c72669ab38637f225a8

Bug description

When I build my docker images, I start the server once to generate cache files. To automatically stop the server, I pipe stop to the process: echo stop | java -jar paper-1.18.2-235.jar nogui.

However, this always causes Essentials to print an error.

Steps to reproduce

Install EssentialsX on an empty Paper server
echo stop | java -jar paper-1.18.2-235.jar nogui

Expected behaviour

EssentialsX closes cleanly

Actual behaviour

EssentialsX prints an error and may not have shut down properly

JRoy · Answer 1 · 2022-03-08T03:55:58.000Z

This is a race condition, you should likely never experience this again and isn't that big of a deal.

nathanfranke · Answer 2 · 2022-03-08T03:58:01.000Z

you should likely never experience this again

I can reproduce it consistently

JRoy · Answer 3 · 2022-03-08T03:59:17.000Z

you should likely never experience this again

I can reproduce it consistently

Hm, in that case this may be something else, can you try on the latest version as we did just make some changes to the update system?

nathanfranke · Answer 4 · 2022-03-08T04:08:46.000Z

Reproduced in EssentialsX-2.19.4-dev+2-3984bdd on paper-1.18.2-235

I don't expect this to be a harmful bug per se, but it's pretty messy to have that error.

mdcfe · Answer 5 · 2022-03-08T12:18:06.000Z

The update checker starts on a separate thread (!?) as soon as the server startup finishes. I assume that this thread isn't being killed when EssentialsX is disabled, so the update checker will keep running until the plugin classloader closes.

nathanfranke · Answer 6 · 2022-04-10T02:15:50.000Z

I think I can still reproduce this, though with a different stack trace.

[21:15:03 INFO]: [Essentials] Disabling Essentials v2.20.0-dev+5-d891268
[21:15:03 WARN]: [Essentials] Plugin Essentials v2.20.0-dev+5-d891268 generated an exception while executing task 6
java.lang.IllegalStateException: zip file closed
        at java.util.zip.ZipFile.ensureOpen(ZipFile.java:831) ~[?:?]
        at java.util.zip.ZipFile.getEntry(ZipFile.java:330) ~[?:?]
        at java.util.jar.JarFile.getEntry(JarFile.java:518) ~[?:?]
        at java.util.jar.JarFile.getJarEntry(JarFile.java:473) ~[?:?]
        at org.bukkit.plugin.java.PluginClassLoader.findClass(PluginClassLoader.java:163) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:587) ~[?:?]
        at org.bukkit.plugin.java.PluginClassLoader.loadClass0(PluginClassLoader.java:108) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at org.bukkit.plugin.java.PluginClassLoader.loadClass(PluginClassLoader.java:103) ~[paper-api-1.18.2-R0.1-SNAPSHOT.jar:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:520) ~[?:?]
        at com.earth2me.essentials.updatecheck.UpdateChecker.tryProcessDistance(UpdateChecker.java:169) ~[EssentialsX-2.20.0-dev+5-d891268.jar:?]
        at com.earth2me.essentials.updatecheck.UpdateChecker.fetchDistance(UpdateChecker.java:202) ~[EssentialsX-2.20.0-dev+5-d891268.jar:?]
        at com.earth2me.essentials.updatecheck.UpdateChecker.lambda$fetchLatestDev$0(UpdateChecker.java:80) ~[EssentialsX-2.20.0-dev+5-d891268.jar:?]
        at org.bukkit.craftbukkit.v1_18_R2.scheduler.CraftTask.run(CraftTask.java:101) ~[paper-1.18.2.jar:git-Paper-283]
        at org.bukkit.craftbukkit.v1_18_R2.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:57) ~[paper-1.18.2.jar:git-Paper-283]
        at com.destroystokyo.paper.ServerSchedulerReportingWrapper.run(ServerSchedulerReportingWrapper.java:22) ~[paper-1.18.2.jar:git-Paper-283]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
        at java.lang.Thread.run(Thread.java:833) ~[?:?]
[21:15:08 ERROR]: Nag author: 'Zenexer' of 'Essentials' about the following: This plugin is not properly shutting down its async tasks when it is being shut down. This task may throw errors during the final shutdown logs and might not complete before process dies.

Share to