search

McJtyMods / RFTools

A set of blocks and items to help with RF in general. Currently contains a Dimension Builder, Teleportation System, Shield System, RF monitor, an RF network debug tool and an automatic crafter
MIT License
228 stars 88 forks source link

Time-out connecting to server with NPE #285

Closed dzrw closed 9 years ago

dzrw commented 9 years ago

I'm running into a timeout problem when connecting to a server which I believe this is related to #136 -- an issue that was closed without resolution. I've spent days trying to figure out what's going on -- attempting to search for Unexpected packet during modded negotiation leads to a dead-end of people claiming that the Forge versions are mismatched: I assure you that that is not the problem here (my server and client are built from the same custom mod library).

However, #136 mentions that a mismatch between the server and client config might be responsible for generating the NPE in mcjty.rftools.dimension.RfToolsDimensionManager.unregisterDimensions which in turn might cause the connection issues.

If that's the case, would you perform a null check and print out a more helpful message to the logs?

The vulnerability is the unchecked usage of instance here. The proximate cause is most likely that RfToolsDimensionManager.getDimensionManager has not been invoked in this pathway (due to a configuration conflict somewhere else?). The reliance on a static instance variable that defaults to null is a code smell -- is there a standard dependency injection framework / IoC container for Minecraft/Java? That's the standard way of solving the singleton initialization problem. I'll dig around and try to figure out whether/if there is a configuration check that prevents a read on getDimensionManager. I'm happy to help you track down this bug to a particular line of code, but I've noticed that maintainers tend to find dubious reasons to not accept PRs to their mods in a timely fashion, so I'll let you actually fix it. No offense.

My server logs contain the following lines:

[03:06:05] [Netty IO #4/INFO] [FML]: Client protocol version 2
[03:06:05] [Netty IO #4/INFO] [FML]: Client attempting to join with 93 mods : NotEnoughItems@1.0.5.null,MineFactoryReloaded|CompatExtraBiomes@1.7.10R2.8.0,Waila@1.5.10,extracells@2.2.73,TConstruct@1.7.10-1.8.5.build957,BuildCraft|Silicon@7.0.17,simplyjetpacks@1.5.1,appliedenergistics2-core@rv2-stable-10,NEIAddons@1.12.11.36,ForgeMicroblock@1.2.0.345,rftools@3.11,BiblioCraft@1.10.3,BuildCraft|Core@7.0.17,HardcoreEnderExpansion@1.8.2,EnderZoo@1.7.10-1.0.11.28,MineFactoryReloaded|CompatTwilightForest@1.7.10R2.8.0,ImmersiveEngineering@0.5.2,bdlib@1.9.1.97,NEIAddons|Developer@1.12.11.36,MineFactoryReloaded|CompatProjRed@1.7.10R2.8.0,mcp@9.05,Mantle@1.7.10-0.3.2.jenkins184,journeymap@@JMVERSION@,appliedenergistics2@rv2-stable-10,BuildCraft|Robotics@7.0.17,MineFactoryReloaded|CompatAtum@1.7.10R2.8.0,MineFactoryReloaded|CompatTConstruct@1.7.10R2.8.0,MineFactoryReloaded|CompatAppliedEnergistics@1.7.10R2.8.0,inventorytweaks@1.58-147-645ca10,MineFactoryReloaded|CompatBuildCraft@1.7.10R2.8.0,harvestcraft@1.7.10i,McMultipart@1.2.0.345,ThermalExpansion@1.7.10R4.0.3B1,BiomesOPlenty@2.1.0,GrimoireOfGaia@1.0.0,BuildCraft|Factory@7.0.17,ExtraUtilities@1.2.8,MineFactoryReloaded|CompatThaumcraft@1.7.10R2.8.0,MineFactoryReloaded|CompatRailcraft@1.7.10R2.8.0,NEIAddons|AppEng@1.12.11.36,MineFactoryReloaded|CompatForestry@1.7.10R2.8.0,EnderStorage@1.4.7.36,ThermalFoundation@1.7.10R1.2.0,MineFactoryReloaded|CompatSufficientBiomes@1.7.10R2.8.0,MineFactoryReloaded|CompatVanilla@1.7.10R2.8.0,ForgeMultipart@1.2.0.345,MineFactoryReloaded|CompatForgeMicroblock@1.7.10R2.8.0,eplus@3.0.2-d,MineFactoryReloaded@1.7.10R2.8.0,EnderIO@1.7.10-2.2.8.381,BuildCraft|Compat@7.0.9,Translocator@1.1.2.15,ProjectE@1.7.10-PE1.8.0,CoFHCore@1.7.10R3.0.3,neiintegration@1.0.11,FastCraft@1.21,Forge@10.13.4.1448,immersiveintegration@0.4.2,IronChest@6.0.60.741,NEIAddons|Botany@1.12.11.36,menagerie@1.0,thecorruptedsector@1.0.1,MineFactoryReloaded|CompatThermalExpansion@1.7.10R2.8.0,gendustry@1.5.2.107,CodeChickenCore@1.0.7.46,BigReactors@0.4.3A,SpiceOfLife@1.2.3,CompactMachines@1.7.10-1.20,ChickenChunks@1.3.4.16,MineFactoryReloaded|CompatChococraft@1.7.10R2.8.0,BuildCraft|Energy@7.0.17,ExtraTiC@1.4.5,MineFactoryReloaded|CompatMystcraft@1.7.10R2.8.0,MineFactoryReloaded|CompatIC2@1.7.10R2.8.0,AppleCore@1.1.0,debug@1.0,ExtrabiomesXL@3.16.2,FML@7.10.99.99,Natura@2.2.0,enderutilities@0.4.1,NEIAddons|Forestry@1.12.11.36,TiCTooltips@1.2.5,BuildCraft|Transport@7.0.17,adventurebackpack@1.7.10-0.8b,chisel@2.4.1.40,ctmlib@1.0.1.5,<CoFH ASM>@000,NEIAddons|CraftingTables@1.12.11.36,NEIAddons|ExNihilo@1.12.11.36,denseores@1.0,Forestry@3.6.3.20,BuildCraft|Builders@7.0.17,MineFactoryReloaded|CompatBackTools@1.7.10R2.8.0
[03:06:05] [Netty IO #4/INFO] [FML]: Attempting connection with missing mods [] at CLIENT
[03:06:07] [Netty IO #4/INFO] [FML]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.client.C00PacketKeepAlive

On the client, I see the following logs:

[20:08:21] [Netty Client IO #5/INFO] [FML/]: Unexpected packet during modded negotiation - assuming vanilla or keepalives : net.minecraft.network.play.server.S00PacketKeepAlive
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: NetworkDispatcher exception
io.netty.handler.timeout.ReadTimeoutException
[20:08:41] [Netty Client IO #5/INFO] [mcjty.rftools.RFTools/]: Disconnect from server: Unregistering RFTools dimensions
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: Exception caught during firing event cpw.mods.fml.common.network.FMLNetworkEvent$ClientDisconnectionFromServerEvent@20eed083:
java.lang.NullPointerException
    at mcjty.rftools.dimension.RfToolsDimensionManager.unregisterDimensions(RfToolsDimensionManager.java:96) ~[RfToolsDimensionManager.class:?]
    at mcjty.rftools.ClientDisconnectEvent.onDisconnectedFromServerEvent(ClientDisconnectEvent.java:13) ~[ClientDisconnectEvent.class:?]
    at cpw.mods.fml.common.eventhandler.ASMEventHandler_552_ClientDisconnectEvent_onDisconnectedFromServerEvent_ClientDisconnectionFromServerEvent.invoke(.dynamic) ~[?:?]
    at cpw.mods.fml.common.eventhandler.ASMEventHandler.invoke(ASMEventHandler.java:54) ~[ASMEventHandler.class:?]
    at cpw.mods.fml.common.eventhandler.EventBus.post(EventBus.java:138) [EventBus.class:?]
    at cpw.mods.fml.common.network.handshake.NetworkDispatcher.close(NetworkDispatcher.java:405) [NetworkDispatcher.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeClose(DefaultChannelHandlerContext.java:560) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.close(DefaultChannelHandlerContext.java:545) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.close(DefaultChannelHandlerContext.java:423) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelPipeline.close(DefaultChannelPipeline.java:826) [DefaultChannelPipeline.class:?]
    at io.netty.channel.AbstractChannel.close(AbstractChannel.java:177) [AbstractChannel.class:?]
    at net.minecraft.network.NetworkManager.func_150718_a(NetworkManager.java:230) [ej.class:?]
    at net.minecraft.network.NetworkManager.exceptionCaught(NetworkManager.java:104) [ej.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [ChannelInboundHandlerAdapter.class:?]
    at cpw.mods.fml.common.network.handshake.NetworkDispatcher.exceptionCaught(NetworkDispatcher.java:487) [NetworkDispatcher.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelHandlerAdapter.exceptionCaught(ChannelHandlerAdapter.java:61) [ChannelHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelHandlerAdapter.exceptionCaught(ChannelHandlerAdapter.java:61) [ChannelHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelHandlerAdapter.exceptionCaught(ChannelHandlerAdapter.java:61) [ChannelHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [ChannelInboundHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [ChannelInboundHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.ChannelInboundHandlerAdapter.exceptionCaught(ChannelInboundHandlerAdapter.java:131) [ChannelInboundHandlerAdapter.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.invokeExceptionCaught(DefaultChannelHandlerContext.java:275) [DefaultChannelHandlerContext.class:?]
    at io.netty.channel.DefaultChannelHandlerContext.fireExceptionCaught(DefaultChannelHandlerContext.java:253) [DefaultChannelHandlerContext.class:?]
    at io.netty.handler.timeout.ReadTimeoutHandler.readTimedOut(ReadTimeoutHandler.java:185) [ReadTimeoutHandler.class:?]
    at io.netty.handler.timeout.ReadTimeoutHandler$ReadTimeoutTask.run(ReadTimeoutHandler.java:211) [ReadTimeoutHandler$ReadTimeoutTask.class:?]
    at io.netty.util.concurrent.PromiseTask$RunnableAdapter.call(PromiseTask.java:38) [PromiseTask$RunnableAdapter.class:?]
    at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:123) [ScheduledFutureTask.class:?]
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:354) [SingleThreadEventExecutor.class:?]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:348) [NioEventLoop.class:?]
    at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101) [SingleThreadEventExecutor$2.class:?]
    at java.lang.Thread.run(Thread.java:745) [?:1.8.0_45]
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: Index: 4 Listeners:
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 0: NORMAL
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 1: ASM: org.dave.CompactMachines.handler.CMEventHandler@5b3d9031 onClientDisconnect(Lcpw/mods/fml/common/network/FMLNetworkEvent$ClientDisconnectionFromServerEvent;)V
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 2: ASM: crazypants.enderio.machine.hypercube.ConnectionHandler@75a3f143 onDisconnectedFromServer(Lcpw/mods/fml/common/network/FMLNetworkEvent$ClientDisconnectionFromServerEvent;)V
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 3: ASM: crazypants.enderio.machine.transceiver.ConnectionHandler@60b163fa onDisconnectedFromServer(Lcpw/mods/fml/common/network/FMLNetworkEvent$ClientDisconnectionFromServerEvent;)V
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 4: ASM: mcjty.rftools.ClientDisconnectEvent@23c78acf onDisconnectedFromServerEvent(Lcpw/mods/fml/common/network/FMLNetworkEvent$ClientDisconnectionFromServerEvent;)V
[20:08:41] [Netty Client IO #5/ERROR] [FML/]: 5: ASM: tonius.simplyjetpacks.handler.SyncHandler@26ccd910 onClientDisconnectedFromServer(Lcpw/mods/fml/common/network/FMLNetworkEvent$ClientDisconnectionFromServerEvent;)V
McJty commented 9 years ago

Hmm. I have the feeling this bug may be caused by something else going wrong and because of that RFTools crashing because some parts haven't been initialized correctly (like that instance). Do you happen to have a full log?

MrBenji285 commented 9 years ago

I had the same problem. The modpack was built with forge 1448, but when I update to forge 1492, the problem disappears.

dzrw commented 9 years ago

I haven't had a chance to get back to this and generate a full log, but I did want to jump on and mention that I'm running Forge 1448. Thanks for the tip @MrBenji285, I'll try to update to 1492 - that might be a "quick fix" that fixes the immediate problem.

It would be interesting to me to figure out what fixed the issue between 1492 and 1448. The idea that @McJty's mods are not being initialized correctly due to a bug in the middleware has got to be frustrating.

Polydiac commented 9 years ago

I encountered a similar Issue with Forge 1492 too on my server. The server runs but none of us can connect to it and get a time out. This is the part of the client log http://pastebin.com/bryhAMgJ

McJty commented 9 years ago

Why exactly do you suspect RFTools is at fault here (to Soro300)? I see nothing in that log indicating that.

Polydiac commented 9 years ago

at mcjty.rftools.dimension.RfToolsDimensionManager.unregisterDimensions(RfToolsDimensionManager.java:96) ~[RfToolsDimensionManager.class:?] at mcjty.rftools.ClientDisconnectEvent.onDisconnectedFromServerEvent(ClientDisconnectEvent.java:14) ~[ClientDisconnectEvent.class:?]

McJty commented 9 years ago

Hmm yes I missed that. But even so that code is called when a client disconnects. So that means this crash is actually a symptom of the problem and not the cause. i.e. because of something causing a timeout this causes the client to disconnect and this causes RFTools to try to unregister that client. Apparently something got corrupted so it fails to do so. Seems a number of things are going wrong here. Can you describe what has happened before this event? Anything special? Are you in rftools dimensions?

Polydiac commented 9 years ago

no the problem is I just set the server up I already fixed a few things and got the server running but now everyone gets a time out.

blade1981m commented 9 years ago

I am also experiencing this on our server. It is a very large modpack, so we were trying to think what else could be causing a conflict based on what mods we have different compared to some of the other popular modpacks out there. One that we have that is different that uses additional dimensions is compact machines which I also notice listed in the modpack above. When I get some more time I will try troubleshooting more to see if it is related to the combination of those two mods, but just figured I would add this note here in case anyone else gets chance to test that on their server before me. On our server we are currently using forge 1481.

blade1981m commented 9 years ago

Ok, so I did finally get to try removing compact machines and re-enabling rftools. Still getting the timed-out issue, so it looks like it is not related to a conflict between these two after all.

ghost commented 9 years ago

I solved this problem by copying Mobius Core and opis from server to client.

What's strange is that I believe I have opis on server but not client at first and the server worked fine. After I modified some cfg files with worldgen the problem happened. I guess it's related with the mapwriter implemented by opis.

Edit: Opis is not necessary, only Mobius Core.

sfPlayer1 commented 8 years ago

The immediate issue is in RFTools and it's caused me quite some annoyance trying to debug disconnect issues.

The initialization is obviously not finished as per https://github.com/McJty/RFTools/issues/285#issuecomment-130154363 since the disconnect event may fire very early for any auxiliary issue while connecting. The event is being fired from the network pipeline's exception handler, so it has to be expected before any other.

hron84 commented 8 years ago

@McJty this bug is appeared to me too, and even if not RFTools causes the crash, this crash hides the real connection problem and prevents MineCraft to throw the real exception. Please reopen this issue and give us an advice what could go wrong here, since this excepton gives absolute no point for users what's wrong. More descriptive exception or throwing the original exception would be better than this NPE.

No Opis/MobiusCore affected on my Side, RFTools 4.13, slightly modded Project Ozone pack.

McJty commented 8 years ago

Well I have no advice to give on this issue as I have absolutely no clue what is going on here and I cannot reproduce this in any way.

McJty commented 8 years ago

However, I suppose I could add a null check though

hron84 commented 8 years ago

@McJty I'd really appreciate if you can.