BentoBox icon indicating copy to clipboard operation
BentoBox copied to clipboard
verified publisher icon BentoBoxWorld

modifying exception handling for completeSetup, now it will print the log and stack traces together

Open 4o4E opened this issue 2 years ago • 2 comments

Before this PR, when an exception occurred during a completeSetup like this, the log would look like the following, with CRITICAL ERROR and stack trace not connected together.

[00:13:44] [Server thread/ERROR]: [BentoBox] *****************CRITICAL ERROR!******************
[00:13:44] [Server thread/ERROR]: [BentoBox] null
[00:13:44] [Server thread/ERROR]: [BentoBox]  Disabling BentoBox...
[00:13:44] [Server thread/ERROR]: [BentoBox] *************************************************
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling addons...
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Level...
[00:13:44] [Server thread/INFO]: [BentoBox] [Level] Stopping Level queue
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v2.9.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling BSkyBlock...
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.16.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling ControlPanel...
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Chat...
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Biomes...
[00:13:44] [Server thread/ERROR]: [BentoBox] Error occurred when disabling addon Biomes
[00:13:44] [Server thread/ERROR]: [BentoBox] Report this to the addon's author(s)
[00:13:44] [Server thread/ERROR]: [BentoBox] [BONNe]
[00:13:44] [Server thread/ERROR]: [BentoBox] java.lang.NullPointerException: Cannot invoke "world.bentobox.biomes.tasks.UpdateQueue.getTask()" because "this.biomeUpdateQueue" is null
	at Biomes-2.0.0.jar//world.bentobox.biomes.BiomesAddon.onDisable(BiomesAddon.java:240)
	at BentoBox-1.21.1.jar//world.bentobox.bentobox.managers.AddonsManager.disable(AddonsManager.java:622)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at BentoBox-1.21.1.jar//world.bentobox.bentobox.managers.AddonsManager.disableAddons(AddonsManager.java:415)
	at BentoBox-1.21.1.jar//world.bentobox.bentobox.BentoBox.fireCriticalError(BentoBox.java:273)
	at BentoBox-1.21.1.jar//world.bentobox.bentobox.BentoBox.lambda$onEnable$0(BentoBox.java:173)
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftTask.run(CraftTask.java:101)
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
	at net.minecraft.server.MinecraftServer.v(MinecraftServer.java:1151)
	at net.minecraft.server.MinecraftServer.lambda$spin$1(MinecraftServer.java:308)
	at java.base/java.lang.Thread.run(Thread.java:833)

[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Warps...
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Limits...
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Bank...
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.4.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling MagicCobblestoneGenerator...
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[00:13:44] [Server thread/INFO]: [BentoBox] Disabling Challenges...
[00:13:44] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[00:13:44] [Server thread/INFO]: [BentoBox] Addons successfully disabled.
[00:13:44] [Server thread/INFO]: [BentoBox] Removing coops from islands...
[00:13:44] [Server thread/INFO]: [BentoBox] Saving islands - this has to be done sync so it may take a while with a lot of islands...
[00:13:44] [Server thread/INFO]: [BentoBox] Islands saved.
[00:13:44] [Server thread/INFO]: [BentoBox] Closing database.
[00:13:44] [Server thread/WARN]: java.util.ConcurrentModificationException
[00:13:44] [Server thread/WARN]: 	at java.base/java.util.WeakHashMap$HashIterator.nextEntry(WeakHashMap.java:809)
[00:13:44] [Server thread/WARN]: 	at java.base/java.util.WeakHashMap$KeyIterator.next(WeakHashMap.java:842)
[00:13:44] [Server thread/WARN]: 	at java.base/java.util.AbstractCollection.finishToArray(AbstractCollection.java:229)
[00:13:44] [Server thread/WARN]: 	at java.base/java.util.AbstractCollection.toArray(AbstractCollection.java:148)
[00:13:44] [Server thread/WARN]: 	at com.google.common.collect.ImmutableSet.copyOf(ImmutableSet.java:238)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.plugin.SimplePluginManager.getDefaultPermSubscriptions(SimplePluginManager.java:937)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.plugin.SimplePluginManager.dirtyPermissibles(SimplePluginManager.java:857)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.plugin.SimplePluginManager.calculatePermissionDefault(SimplePluginManager.java:845)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:806)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:794)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:26)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:18)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:62)
[00:13:44] [Server thread/WARN]: 	at BentoBox-1.21.1.jar//world.bentobox.bentobox.managers.AddonsManager.registerPermission(AddonsManager.java:290)
[00:13:44] [Server thread/WARN]: 	at BentoBox-1.21.1.jar//world.bentobox.bentobox.managers.AddonsManager.setPerms(AddonsManager.java:265)
[00:13:44] [Server thread/WARN]: 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
[00:13:44] [Server thread/WARN]: 	at BentoBox-1.21.1.jar//world.bentobox.bentobox.managers.AddonsManager.enableAddons(AddonsManager.java:254)
[00:13:44] [Server thread/WARN]: 	at BentoBox-1.21.1.jar//world.bentobox.bentobox.BentoBox.completeSetup(BentoBox.java:188)
[00:13:44] [Server thread/WARN]: 	at BentoBox-1.21.1.jar//world.bentobox.bentobox.BentoBox.lambda$onEnable$0(BentoBox.java:171)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftTask.run(CraftTask.java:101)
[00:13:44] [Server thread/WARN]: 	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
[00:13:44] [Server thread/WARN]: 	at net.minecraft.server.MinecraftServer.v(MinecraftServer.java:1151)
[00:13:44] [Server thread/WARN]: 	at net.minecraft.server.MinecraftServer.lambda$spin$1(MinecraftServer.java:308)
[00:13:44] [Server thread/WARN]: 	at java.base/java.lang.Thread.run(Thread.java:833)

After this PR, the logs will be as follows

[22:34:31] [Server thread/WARN]: [BentoBox] unexpected exception occurred during completeSetup, Disabling BentoBox...
java.util.ConcurrentModificationException: null
	at java.util.WeakHashMap$HashIterator.nextEntry(WeakHashMap.java:809) ~[?:?]
	at java.util.WeakHashMap$KeyIterator.next(WeakHashMap.java:842) ~[?:?]
	at java.util.AbstractCollection.toArray(AbstractCollection.java:146) ~[?:?]
	at com.google.common.collect.ImmutableSet.copyOf(ImmutableSet.java:238) ~[guava-31.0.1-jre.jar:?]
	at org.bukkit.plugin.SimplePluginManager.getDefaultPermSubscriptions(SimplePluginManager.java:937) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.dirtyPermissibles(SimplePluginManager.java:857) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.calculatePermissionDefault(SimplePluginManager.java:845) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:806) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:794) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:26) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:18) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:62) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at world.bentobox.bentobox.managers.AddonsManager.registerPermission(AddonsManager.java:282) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.managers.AddonsManager.setPerms(AddonsManager.java:250) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at java.util.ArrayList.forEach(ArrayList.java:1511) ~[?:?]
	at world.bentobox.bentobox.managers.AddonsManager.enableAddons(AddonsManager.java:239) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.BentoBox.completeSetup(BentoBox.java:196) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.BentoBox.lambda$onEnable$0(BentoBox.java:172) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftTask.run(CraftTask.java:101) ~[purpur-1.19.jar:git-Purpur-1735]
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483) ~[purpur-1.19.jar:git-Purpur-1735]
	at net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1151) ~[purpur-1.19.jar:git-Purpur-1735]
	at net.minecraft.server.MinecraftServer.lambda$spin$1(MinecraftServer.java:308) ~[purpur-1.19.jar:git-Purpur-1735]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling addons...
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Level...
[22:34:31] [Server thread/INFO]: [BentoBox] [Level] Stopping Level queue
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v2.9.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling BSkyBlock...
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.16.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling ControlPanel...
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Chat...
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Biomes...
[22:34:31] [Server thread/ERROR]: [BentoBox] Error occurred when disabling addon Biomes
[22:34:31] [Server thread/ERROR]: [BentoBox] Report this to the addon's author(s)
[22:34:31] [Server thread/ERROR]: [BentoBox] [BONNe]
[22:34:31] [Server thread/ERROR]: [BentoBox] java.lang.NullPointerException: Cannot invoke "world.bentobox.biomes.tasks.UpdateQueue.getTask()" because "this.biomeUpdateQueue" is null
	at Biomes-2.0.0.jar//world.bentobox.biomes.BiomesAddon.onDisable(BiomesAddon.java:240)
	at BentoBox-1.21.1-SNAPSHOT-LOCAL.jar//world.bentobox.bentobox.managers.AddonsManager.disable(AddonsManager.java:626)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at BentoBox-1.21.1-SNAPSHOT-LOCAL.jar//world.bentobox.bentobox.managers.AddonsManager.disableAddons(AddonsManager.java:411)
	at BentoBox-1.21.1-SNAPSHOT-LOCAL.jar//world.bentobox.bentobox.BentoBox.lambda$onEnable$0(BentoBox.java:180)
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftTask.run(CraftTask.java:101)
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483)
	at net.minecraft.server.MinecraftServer.v(MinecraftServer.java:1151)
	at net.minecraft.server.MinecraftServer.lambda$spin$1(MinecraftServer.java:308)
	at java.base/java.lang.Thread.run(Thread.java:833)

[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Warps...
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Limits...
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Bank...
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.4.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling MagicCobblestoneGenerator...
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[22:34:31] [Server thread/INFO]: [BentoBox] Disabling Challenges...
[22:34:31] [Server thread/INFO]: [Pladdon] Disabling Pladdon v1.0
[22:34:31] [Server thread/INFO]: [BentoBox] Addons successfully disabled.
[22:34:31] [Server thread/INFO]: [BentoBox] Removing coops from islands...
[22:34:31] [Server thread/INFO]: [BentoBox] Saving islands - this has to be done sync so it may take a while with a lot of islands...
[22:34:31] [Server thread/INFO]: [BentoBox] Islands saved.
[22:34:31] [Server thread/INFO]: [BentoBox] Closing database.

Regarding the reason for this exception, I suspect that other plugins have run asynchronous tasks to modify permissions, but further testing is needed to determine the cause. Currently, this exception can be replicated multiple times on my server.

Perhaps it is possible to advance permission registration to onEnable?

4o4E avatar Jun 29 '23 15:06 4o4E

Null-pointer in Biomes is not relevant to the issue. Which addon was BentoBox enabling when the crash occurred?

What exactly happened before:

[00:13:44] [Server thread/ERROR]: [BentoBox] *****************CRITICAL ERROR!******************
[00:13:44] [Server thread/ERROR]: [BentoBox] null
[00:13:44] [Server thread/ERROR]: [BentoBox]  Disabling BentoBox...
[00:13:44] [Server thread/ERROR]: [BentoBox] *************************************************

BONNe avatar Jun 29 '23 18:06 BONNe

Null-pointer in Biomes is not relevant to the issue. Which addon was BentoBox enabling when the crash occurred?

What exactly happened before:

[00:13:44] [Server thread/ERROR]: [BentoBox] *****************CRITICAL ERROR!******************
[00:13:44] [Server thread/ERROR]: [BentoBox] null
[00:13:44] [Server thread/ERROR]: [BentoBox]  Disabling BentoBox...
[00:13:44] [Server thread/ERROR]: [BentoBox] *************************************************

not npe in biome, look at this exception, that's what caused the problem, looks like other plugins are registering permissions at the same time

[22:34:31] [Server thread/WARN]: [BentoBox] unexpected exception occurred during completeSetup, Disabling BentoBox...
java.util.ConcurrentModificationException: null
	at java.util.WeakHashMap$HashIterator.nextEntry(WeakHashMap.java:809) ~[?:?]
	at java.util.WeakHashMap$KeyIterator.next(WeakHashMap.java:842) ~[?:?]
	at java.util.AbstractCollection.toArray(AbstractCollection.java:146) ~[?:?]
	at com.google.common.collect.ImmutableSet.copyOf(ImmutableSet.java:238) ~[guava-31.0.1-jre.jar:?]
	at org.bukkit.plugin.SimplePluginManager.getDefaultPermSubscriptions(SimplePluginManager.java:937) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.dirtyPermissibles(SimplePluginManager.java:857) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.calculatePermissionDefault(SimplePluginManager.java:845) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:806) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.plugin.SimplePluginManager.addPermission(SimplePluginManager.java:794) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:26) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:18) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at org.bukkit.util.permissions.DefaultPermissions.registerPermission(DefaultPermissions.java:62) ~[purpur-api-1.19-R0.1-SNAPSHOT.jar:?]
	at world.bentobox.bentobox.managers.AddonsManager.registerPermission(AddonsManager.java:282) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.managers.AddonsManager.setPerms(AddonsManager.java:250) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at java.util.ArrayList.forEach(ArrayList.java:1511) ~[?:?]
	at world.bentobox.bentobox.managers.AddonsManager.enableAddons(AddonsManager.java:239) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.BentoBox.completeSetup(BentoBox.java:196) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at world.bentobox.bentobox.BentoBox.lambda$onEnable$0(BentoBox.java:172) ~[BentoBox-1.21.1-SNAPSHOT-LOCAL.jar:?]
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftTask.run(CraftTask.java:101) ~[purpur-1.19.jar:git-Purpur-1735]
	at org.bukkit.craftbukkit.v1_19_R1.scheduler.CraftScheduler.mainThreadHeartbeat(CraftScheduler.java:483) ~[purpur-1.19.jar:git-Purpur-1735]
	at net.minecraft.server.MinecraftServer.runServer(MinecraftServer.java:1151) ~[purpur-1.19.jar:git-Purpur-1735]
	at net.minecraft.server.MinecraftServer.lambda$spin$1(MinecraftServer.java:308) ~[purpur-1.19.jar:git-Purpur-1735]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]

btw, the previous implementation, will first execute fireCriticalError, which will execute onDisable before printing the stack trace

4o4E avatar Jun 30 '23 02:06 4o4E