players kicked at random intervals after making mining drill: IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly

Question

players kicked at random intervals after making mining drill: IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly

Docsmurf opened this issue 4 years ago · 16 comments

Docsmurf commented 4 years ago

Description of the issue:

Starting today: Multiple players are being kicked at random with the error

[Netty Server IO 3/ERROR] [net.minecraft.network.NettyPacketEncoder/]: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly

This issue is Optifine independent and is happening to users with and without the mod

This is not a crash and simply kicks players from the server. It happens seemingly at random. The only commonality is all users that started having the issue recently crafted and used the mining drill. Some players have stopped encountering the issue after they killed themselves and their player data was cleared from the server completely and they stopped using the drill. THIS has not fixed the issue for others. The server is running barely any mods.

Biomes o plenty 13.0.0.426 ( adds 97 additional biomes )
Fallintree 2.8.1 ( fells trees in one axe swing)
IE 4.1.2-129 ( this mod)
Jei-7.6.0.55 (client and server)
Upstream 1.0 ( makes better rivers)

It is not possibly to test for this issue with BOP stripped from the server but the integration has seemingly worked fine for over a week

Client and server running forge 1.16.4 25.1.15

please advise on any additional logs required. I've never had to make a report before so let me know if there are files you need or more info required. i saw what may be a similar issue in the list referencing players getting kicked after using tools but that user never responded to your request for more info.

BluSunrize · Answer 1 · 2021-01-03T10:17:42.000Z

"Additional logs" implies you have given us any logs so far.

The respective server and client logs would be a good start.

Deleted user · Answer 2 · 2021-01-06T14:11:26.000Z

I can confirm this issue, separate server and modlist. Client logs show nothing when the client gets kicked, it's very weird. Even players that have never made or touched a drill get kicked.

[06Jan2021 07:03:59.711] [Netty Server IO #5/ERROR] [net.minecraft.network.NettyPacketEncoder/]: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly [06Jan2021 07:03:59.759] [Server thread/INFO] [net.minecraft.network.play.ServerPlayNetHandler/]: Anonymous lost connection: Internal Exception: io.netty.handler.codec.EncoderException: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly

This is what server log throws when a client gets kicked.

phil-flip · Answer 3 · 2021-01-11T14:10:47.000Z

Everyone else gets disconnected, when I hold the Buzzsaw or the Mining Drill in the inventory

BluSunrize · Answer 4 · 2021-01-11T14:21:42.000Z

Yeah but none of you lot have actually provided logs.
A server log of the time it happened (the 5 minutes before and after) and a full client log. That's information we need.

phil-flip · Answer 5 · 2021-01-11T12:59:57.000Z

I currently have a server owner, that reports the same issue.

phil-flip · Answer 6 · 2021-01-11T17:17:39.000Z

The issue happened to a friend of mine, not exactly myself. So I would need to recreate the server as well to reproduce the bug. Besides only the other players get kicked. Not the person itself, holding the item. Which makes it harder for me to test it on my own.

I can provide a mod list, my friend uses on their server.

		forge-1.16.4-35.1.36-server.jar                  
		useful_backpacks-1.16.4-1.11.6.86.jar             
		ImmersiveEngineering-1.16.4-4.1.2-129.jar         
		u_team_core-1.16.4-3.1.17.191.jar                 
		BiomesOPlenty-1.16.4-13.0.0.427-universal.jar    
		SimpleCoreLib-1.16.4-2.0.4.3.jar                 
		jei-1.16.4-7.6.1.65.jar                          
		OptiForge-MC1.16.4-0.4.5.jar                     
		ChickenChunks-1.16.4-2.7.0.85-universal.jar       
		forge-1.16.4-35.1.36-universal.jar                
		FastLeafDecay-v25.jar                            
		CodeChickenLib-1.16.4-3.5.0.401-universal.jar     
		Xaeros_Minimap_21.0.0_Forge_1.16.4.jar           
		SimpleOres2-1.16.4-2.4.3.10.jar                  
		gravestone-1.16.4-1.0.8.jar                      
		Clumps-6.0.0.13.jar                              
		XaerosWorldMap_1.11.7_Forge_1.16.4.jar           
		ironchest-1.16.4-11.2.10.jar

malte0811 · Answer 7 · 2021-01-11T15:52:33.000Z

Unfortunately this is one of the places where MC swallows the stack trace (i.e. where the error happened). I haven't been able to reproduce the issue, so it would be great if if one of you could throw this mod on your server until the issue happens again, and then post log files with the mod present.
The mod is a build of my "Mixin Playground" project, in this case with this Mixin.

malte0811 · Answer 8 · 2021-01-18T08:39:21.000Z

The stacktrace seems to be an unrelated issue (or at least I don't see how it would cause the main error). I assume you did not use the mod I posted in #4547 (comment) (unless I messed up that build)?

UnseenAcademical · Answer 9 · 2021-01-18T08:41:46.000Z

Haven't had a chance to try it, only encountered the error very seriously tonight. I'll install the mod during our next modpack update and let you know.

UnseenAcademical · Answer 10 · 2021-01-18T06:43:00.000Z

Error log we captured on this issue, looks like it causes the error at random on players OTHER than the drill user in our case. Persisted at random for over an hour before the drill user logged out, then it stopped abruptly.

[17.01 19:41:33] [Server] [Server thread/FATAL] [minecraft/ThreadTaskExecutor]: Error executing task on Server
[17.01 19:41:33] [Server] java.lang.NullPointerExceptionnull
[17.01 19:41:33] [Server] at blusunrize.immersiveengineering.common.items.DrillItem.consumeDurability(DrillItem.java:360) ~[immersiveengineering:?] {re:classloading,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at blusunrize.immersiveengineering.common.items.DrillItem.func_77644_a(DrillItem.java:313) ~[immersiveengineering:?] {re:classloading,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.item.ItemStack.func_77961_a(ItemStack.java:319) ~[?:?] {re:mixin,pl:runtimedistcleaner:A,re:classloading,xf:fml:apotheosis:apothitemusehook,pl:mixin:APP:performant.mixins.json:item.ItemStackMixin,pl:mixin:APP:quark.mixins.json:ItemStackMixin,pl:mixin:A,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.entity.player.PlayerEntity.func_71059_n(PlayerEntity.java:1164) ~[?:?] {re:computing_frames,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,xf:fml:xaeroworldmap:xaero_wm_playerentity_iswearing,xf:fml:xaerominimap:xaero_playerentity_iswearing,pl:mixin:APP:endergetic.mixins.json:PlayerEntityMixin,pl:mixin:A,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.entity.player.ServerPlayerEntity.func_71059_n(ServerPlayerEntity.java:1291) ~[?:?] {re:computing_frames,pl:accesstransformer:B,re:mixin,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B,pl:mixin:APP:performant.mixins.json:advancement.ServerPlayerEntityMixin,pl:mixin:APP:endergetic.mixins.json:ServerPlayerEntityMixin,pl:mixin:APP:performant.mixins.json:entity.ServerPlayerEntityMixin,pl:mixin:A}
[17.01 19:41:33] [Server] at net.minecraft.network.play.ServerPlayNetHandler.func_147340_a(ServerPlayNetHandler.java:1205) ~[?:?] {re:mixin,pl:accesstransformer:B,re:classloading,pl:accesstransformer:B,pl:mixin:A}
[17.01 19:41:33] [Server] at net.minecraft.network.play.client.CUseEntityPacket.func_148833_a(SourceFile:74) ~[?:?] {re:classloading}
[17.01 19:41:33] [Server] at net.minecraft.network.play.client.CUseEntityPacket.func_148833_a(SourceFile:13) ~[?:?] {re:classloading}
[17.01 19:41:33] [Server] at net.minecraft.network.PacketThreadUtil.func_225383_a(SourceFile:21) ~[?:?] {re:classloading}
[17.01 19:41:33] [Server] at net.minecraft.util.concurrent.TickDelayedTask.run(SourceFile:18) ~[?:?] {re:classloading}
[17.01 19:41:33] [Server] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213166_h(SourceFile:144) ~[?:?] {re:classloading,pl:accesstransformer:B}
[17.01 19:41:33] [Server] at net.minecraft.util.concurrent.RecursiveEventLoop.func_213166_h(SourceFile:23) ~[?:?] {re:classloading}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:733) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_213166_h(MinecraftServer.java:159) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213168_p(SourceFile:118) ~[?:?] {re:classloading,pl:accesstransformer:B}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_213205_aW(MinecraftServer.java:716) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_213168_p(MinecraftServer.java:710) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.util.concurrent.ThreadTaskExecutor.func_213161_c(SourceFile:127) ~[?:?] {re:classloading,pl:accesstransformer:B}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_213202_o(MinecraftServer.java:696) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.func_240802_v_(MinecraftServer.java:645) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at net.minecraft.server.MinecraftServer.lambda$startServer$0(MinecraftServer.java:232) ~[?:?] {re:mixin,pl:accesstransformer:B,pl:runtimedistcleaner:A,re:classloading,pl:accesstransformer:B,pl:runtimedistcleaner:A}
[17.01 19:41:33] [Server] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_{}
[17.01 19:41:36] [Server] [Netty Epoll Server IO #1/ERROR] [minecraft/NettyPacketEncoder]: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly
[17.01 19:41:36] [Disconnect] S0phty has disconnected, reasonInternal Exception: io.netty.handler.codec.EncoderException: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly

Docsmurf · Answer 11 · 2021-01-19T01:47:36.000Z

Well this seems to still be alive.
Honestly i haven't implemented the mod either. we haven't had the crash but we also have not had anyone using the drill.
We haven't been playing as much. Hopefully @UnseenAcademical can toss that mod in and see if we can get more info.

Sorry for going mia i've just been supper busy and haven't gotten complaints from anyone playing about this being a serious issue in about 10 days.

UnseenAcademical · Answer 12 · 2021-01-19T10:24:16.000Z

[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/ERROR] [minecraft/NettyPacketEncoder]: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraftforge.common.util.LazyOptional.getValueUnsafe(LazyOptional.java:133)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraftforge.common.util.LazyOptional.map(LazyOptional.java:206)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at blusunrize.immersiveengineering.common.items.DrillItem.getHead(DrillItem.java:243)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at blusunrize.immersiveengineering.common.items.DrillItem.getShareTag(DrillItem.java:134)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraftforge.common.extensions.IForgeItemStack.getShareTag(IForgeItemStack.java:374)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.PacketBuffer.writeItemStack(PacketBuffer.java:313)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.PacketBuffer.func_150788_a(PacketBuffer.java:295)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.play.server.SEntityEquipmentPacket.func_148840_b(SourceFile:54)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.NettyPacketEncoder.encode(SourceFile:46)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.NettyPacketEncoder.encode(SourceFile:15)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.handler.codec.MessageToByteEncoder.write(MessageToByteEncoder.java:107)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:738)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:801)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:831)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1071)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:300)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at net.minecraft.network.NetworkManager.lambda$dispatchPacket$5(NetworkManager.java:196)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:313)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:884)
[19.01 02:23:29] [Server] [Netty Epoll Server IO #1/INFO] [STDERR/]: [net.minecraft.network.NettyPacketEncoder:redirect$zzk000$redirectError:518]: at java.lang.Thread.run(Thread.java:748)
[19.01 02:23:29] [Disconnect] UnseenAcademical has disconnected, reasonInternal Exception: io.netty.handler.codec.EncoderException: java.lang.IllegalStateException: LazyOptional is empty or otherwise returned null from getValue() unexpectedly
[19.01 02:23:29] [Server] [Server thread/INFO] [minecraft/DedicatedServer]: UnseenAcademical left the game

BluSunrize · Answer 13 · 2021-01-19T11:20:41.000Z

Can you please start using gist or pastebin for your logs? This is dreadful to read.

mindforger · Answer 14 · 2021-01-19T11:47:27.000Z

would a simple nullcheck on getShareTag() help? it is @nullable, so this may be the issue there?

if(stack != null && !getHead(Stack).isEmpty())

malte0811 · Answer 15 · 2021-01-19T12:19:03.000Z

No, that is not the problem, it's crashing inside LazyOptional. I think I understand why it's crashing (a race condition while the LO is being resolved), I still need to figure out why it's being resolved this often though.

malte0811 · Answer 16 · 2021-01-19T20:42:36.000Z

I'm still not sure why there would be so much contention here: I didn't see any unexpected calls while debugging, and the expected ones aren't enough to explain this. However 087c55e should at least fix the disconnects (I referenced the wrong issue in the commit message).

Share to

Description of the issue: