AlmuraDev / SGCraft

Stargates mod for Minecraft
https://www.almuramc.com/sgcraft/SGCraft.html
MIT License
31 stars 31 forks source link

Bad multithreading with ComputerCraft interface #88

Closed LemADEC closed 4 years ago

LemADEC commented 5 years ago

As of SGCraft-2.0.0-beta-6 + 1.12.2-2825-7.1.6-RC3708, bad multithreading is reported in relation with CC Peripheral API.

CCSGPeripheral.detach: from dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@55b7922c
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*********************************************************************************************************************/
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*                                             Illegal Async Chunk Load                                              */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*********************************************************************************************************************/
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /* Sponge relies on knowing when chunks are being loaded as chunks add entities to                                   */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /* the parented world for management. These operations are generally not threadsafe                                  */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /* and shouldn't be considered a "Sponge bug ". Adding/removing entities from                                        */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /* another thread to the world is never ok.                                                                          */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*                                                                                                                   */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*  Chunk Pos : -97, -117                                                                                            */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*                                                                                                                   */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /* java.lang.Exception: Async Chunk Load Detected                                                                    */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.chunk.Chunk.handler$startLoad$bak000(Chunk.java:7292)                                     */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.chunk.Chunk.func_76631_c(Chunk.java)                                                      */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraftforge.common.chunkio.ChunkIOProvider.syncCallback(ChunkIOProvider.java:109)                      */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraftforge.common.chunkio.ChunkIOExecutor.syncChunkLoad(ChunkIOExecutor.java:94)                      */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.gen.ChunkProviderServer.loadChunk(ChunkProviderServer.java:118)                           */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.gen.ChunkProviderServer.func_186028_c(ChunkProviderServer.java:89)                        */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.gen.ChunkProviderServer.redirect$onProvideChunkHead$znl000(ChunkProviderServer.java:1178) */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.gen.ChunkProviderServer.func_186025_d(ChunkProviderServer.java:135)                       */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.World.func_72964_e(World.java:310)                                                        */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.World.func_175726_f(World.java:305)                                                       */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     net.minecraft.world.World.func_175625_s(World.java:7505)                                                      */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     gcewing.sg.features.cc.CCSGPeripheral.getInterfaceTE(CCSGPeripheral.java:113)                                 */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     gcewing.sg.features.cc.CCSGPeripheral.detach(CCSGPeripheral.java:150)                                         */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper.detach(PeripheralAPI.java:90)                  */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     dan200.computercraft.core.apis.PeripheralAPI.shutdown(PeripheralAPI.java:315)                                 */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     dan200.computercraft.core.computer.ComputerExecutor.shutdown(ComputerExecutor.java:481)                       */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     dan200.computercraft.core.computer.ComputerExecutor.work(ComputerExecutor.java:591)                           */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     dan200.computercraft.core.computer.ComputerThread$TaskRunner.run(ComputerThread.java:493)                     */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*     java.lang.Thread.run(Thread.java:748)                                                                         */
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [Sponge]: /*********************************************************************************************************************/
[03:02:02] [ComputerCraft-Computer-Runner-0/ERROR] [computercraft]: Error running task on computer #11
java.lang.IllegalStateException: CauseStackManager called from off main thread (current='Thread{class=class java.lang.Thread, name=ComputerCraft-Computer-Runner-0, priority=5, group=java.lang.ThreadGroup[name=ComputerCraft-Computer-Runner,maxpri=10]}', expected='Thread{class=class java.lang.Thread, name=Server thread, priority=5, group=net.minecraftforge.fml.common.thread.SidedThreadGr
oup[name=SERVER,maxpri=10]}')!
>       at org.spongepowered.common.event.SpongeCauseStackManager.enforceMainThread(SpongeCauseStackManager.java:86) ~[SpongeCauseStackManager.class:1.12.2-2825-7.1.6-RC3708]
>       at org.spongepowered.common.event.SpongeCauseStackManager.pushCauseFrame(SpongeCauseStackManager.java:208) ~[SpongeCauseStackManager.class:1.12.2-2825-7.1.6-RC3708]
>       at net.minecraft.world.WorldServer.handler$spongeLoadEntities$znd000(WorldServer.java:3303) ~[oo.class:?]
>       at net.minecraft.world.WorldServer.func_175650_b(WorldServer.java) ~[oo.class:?]
>       at net.minecraft.world.chunk.Chunk.func_76631_c(Chunk.java:860) ~[axw.class:?]
>       at net.minecraftforge.common.chunkio.ChunkIOProvider.syncCallback(ChunkIOProvider.java:109) ~[ChunkIOProvider.class:?]
>       at net.minecraftforge.common.chunkio.ChunkIOExecutor.syncChunkLoad(ChunkIOExecutor.java:94) ~[ChunkIOExecutor.class:?]
>       at net.minecraft.world.gen.ChunkProviderServer.loadChunk(ChunkProviderServer.java:118) ~[on.class:?]
>       at net.minecraft.world.gen.ChunkProviderServer.func_186028_c(ChunkProviderServer.java:89) ~[on.class:?]
>       at net.minecraft.world.gen.ChunkProviderServer.redirect$onProvideChunkHead$znl000(ChunkProviderServer.java:1178) ~[on.class:?]
>       at net.minecraft.world.gen.ChunkProviderServer.func_186025_d(ChunkProviderServer.java:135) ~[on.class:?]
>       at net.minecraft.world.World.func_72964_e(World.java:310) ~[amu.class:?]
>       at net.minecraft.world.World.func_175726_f(World.java:305) ~[amu.class:?]
>       at net.minecraft.world.World.func_175625_s(World.java:7505) ~[amu.class:?]
>       at gcewing.sg.features.cc.CCSGPeripheral.getInterfaceTE(CCSGPeripheral.java:113) ~[CCSGPeripheral.class:?]
>       at gcewing.sg.features.cc.CCSGPeripheral.detach(CCSGPeripheral.java:150) ~[CCSGPeripheral.class:?]
>       at dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper.detach(PeripheralAPI.java:90) ~[PeripheralAPI$PeripheralWrapper.class:?]
>       at dan200.computercraft.core.apis.PeripheralAPI.shutdown(PeripheralAPI.java:315) ~[PeripheralAPI.class:?]
>       at dan200.computercraft.core.computer.ComputerExecutor.shutdown(ComputerExecutor.java:481) ~[ComputerExecutor.class:?]
>       at dan200.computercraft.core.computer.ComputerExecutor.work(ComputerExecutor.java:591) ~[ComputerExecutor.class:?]
>       at dan200.computercraft.core.computer.ComputerThread$TaskRunner.run(ComputerThread.java:493) [ComputerThread$TaskRunner.class:?]
>       at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]
CCSGPeripheral.attach: to dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@2172dcfd

The IPeripheral interface is implemented in very usual ways here. IPeripheral is normally implemented in the TileEntity itself for simple performance reasons.

Dockter commented 5 years ago

This isn't SGCraft, its Computercraft. They are calling world changing / loading events off the main thread.

LemADEC commented 5 years ago

My mod use ComputerCraft extensively and never trigger that issue. Here, I see CCSGPeripheral.getInterfaceTE() trying to load a chunk off the main thread.

Dockter commented 5 years ago

I understand that but the computercraft method, which likely is a packet, is calling the getInterfaceTE() via a thread that isn't main-thread. I'll try and see if there is a way around this. Sponge is alerting the issue because you shouldn't ever load stuff off the main thread.

LemADEC commented 5 years ago

It's not network based. ComputerCraft use threads to execute Lua scripts. The API tells explicitly that certain (most) methods in there aren't called from the main thread and it's up to your implementation to deal accordingly. ComputerCraft calls detatch() in SGCraft. The latest calls getTileEntity() which do invalid chunk loading.

Dockter commented 5 years ago

What do you suggest?

liach commented 5 years ago

Computer craft should only ever parse the lua script off thread... they should never execute it off-thread if they give scripts permission to access or modify levels/world. If you want an alternative mod, I suggest Computronics.

LemADEC commented 5 years ago

Dockter,

A ComputerCraft IPeripheral is best implemented as part of the TileEntity itself. Every method you present through ComputerCraft should: 1- only manipulate properties of the tile entity (of atomic type or with read/write priorities) 2- never load chunks (so check carefully before getting a block) 3- never write into the world (creating entities, placing blocks, etc.)

Every time you send an event to Lua, it'll be synchronized on the main thread.

You can use Forge Optional to avoid an hard dependency with ComputerCraft, like so:

@Optional.InterfaceList({
    @Optional.Interface(iface = "dan200.computercraft.api.peripheral.IPeripheral", modid = "computercraft")
})
public class TileEntityXXX implements IPeripheral {
...
@Optional.Method(modid = "computercraft")
public String getType() {
...
}
}

Last but not least, you want to consider CC:Tweaked instead of the original ComputerCraft. It's maintained and includes many fixes/improvements.

OpenComputers has a different approach to its API but it tends to the same constrains.

You can ask for help for Computers mods on SquidDev discord, here: https://discord.gg/H2UyJXe

liach,

Lua only gives access to what's defined my peripherals. It's up to said peripherals to handle the actual world access through the main thread.

Computronics is an extension to ComputerCraft or OpenComputers, not a replacement. As such, I don't understand what you mean by alternative here. By experience, Computronics 'overwrites' ComputerCraft peripheral handling which cause various issues. It also increases server lag significantly, so I tend to avoid that mod.

Dockter commented 5 years ago

@LemADEC these mothods are only getting the TE, the function of getting the TE is loading the world file so point 1 is automatically irrelevant since I have to get the TE to start with.

Dockter commented 5 years ago

I will admit though that I am not in a place where Im going to start modifying all of our TE's to account for OC/CC. I lack the knowledge to do such a thing to be honest.

LemADEC commented 5 years ago

You don't need to get the related TileEntity when your object is actually the TileEntity. From what I could find, there's only 1 block behaving as a CC peripheral, so it shouldn't be too hard to restructure. I guess OC is the same story.

Dockter commented 4 years ago

@LemADEC give the above commit a try and see if that helps your issue please.

LemADEC commented 4 years ago

Upgrading from 2.0.2 to build 1d9f1d9dd610666d6ae72308cb3182dd274b9990, I'm getting a phase state error due to NPE in ZPM console:

[07:28:57] [Server thread/ERROR] [Sponge]: /***************************************************************************************************/
[07:28:57] [Server thread/ERROR] [Sponge]: /*                             Exception occurred during a PhaseState                              */
[07:28:57] [Server thread/ERROR] [Sponge]: /***************************************************************************************************/
[07:28:57] [Server thread/ERROR] [Sponge]: /* Sponge's tracking system makes a best effort to not throw exceptions randomly                   */
[07:28:57] [Server thread/ERROR] [Sponge]: /* but sometimes it is inevitable. In most cases, something else triggered this                    */
[07:28:57] [Server thread/ERROR] [Sponge]: /* exception and Sponge prevented a crash by catching it. The following stacktrace                 */
[07:28:57] [Server thread/ERROR] [Sponge]: /* can be used to help pinpoint the cause.                                                         */
[07:28:57] [Server thread/ERROR] [Sponge]: /***************************************************************************************************/
[07:28:57] [Server thread/ERROR] [Sponge]: /* The PhaseState having an exception: Tick{TileEntity}                                            */
[07:28:57] [Server thread/ERROR] [Sponge]: /* The PhaseContext:                                                                               */
[07:28:57] [Server thread/ERROR] [Sponge]: /* org.spongepowered.asm.util.PrettyPrinter@3229b4de                                               */
[07:28:57] [Server thread/ERROR] [Sponge]: /*                                                                                                 */
[07:28:57] [Server thread/ERROR] [Sponge]: /*  StackTrace :                                                                                   */
[07:28:57] [Server thread/ERROR] [Sponge]: /* java.lang.NullPointerException: null                                                            */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     gcewing.sg.features.zpm.console.ZpmConsoleTE.func_73660_a(ZpmConsoleTE.java:329)            */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     org.spongepowered.common.event.tracking.TrackingUtil.tickTileEntity(TrackingUtil.java:237)  */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.world.WorldServer.updateTileEntity(WorldServer.java:5228)                     */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.world.WorldServer.redirect$onUpdateTileEntities$zma000(WorldServer.java:5212) */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.world.World.func_72939_s(World.java:1835)                                     */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.world.WorldServer.func_72939_s(WorldServer.java:4430)                         */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:767)                 */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:397)       */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668)                 */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526)                          */
[07:28:57] [Server thread/ERROR] [Sponge]: /*     java.lang.Thread.run(Thread.java:748)                                                       */
[07:28:57] [Server thread/ERROR] [Sponge]: /*                                                                                                 */
[07:28:57] [Server thread/ERROR] [Sponge]: /* Minecraft : 1.12.2                                                                              */
[07:28:57] [Server thread/ERROR] [Sponge]: /* SpongeAPI : 7.1.0-2ad94d346                                                                     */
[07:28:57] [Server thread/ERROR] [Sponge]: /* Sponge : 1.12.2-7.1.7-SNAPSHOT                                                                  */
[07:28:57] [Server thread/ERROR] [Sponge]: /* SpongeForge : 1.12.2-2838-7.1.7-RC3928                                                          */
[07:28:57] [Server thread/ERROR] [Sponge]: /* Minecraft Forge : 14.23.5.2836                                                                  */
[07:28:57] [Server thread/ERROR] [Sponge]: /***************************************************************************************************/

Tell me if you want a separate issue for that one.

As for the computer interface, there's still issue with attach/detach. Specifically, when placing a second computer, there's extra attach & detach events popping up. Here's logs from my mod, then from that build of SGCraft:

[07:57:32] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: test WD
[07:57:33] [Server thread                  /INFO] [warpdrive]: [CC] IPeripheralProvider.getPeripheral @ Spacheese (265 71 234) west TileEntityAirGeneratorTiered '' @ Spacheese (265 71 234)
[07:57:38] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: Computer 1 placed
[07:57:39] [ComputerCraft-Computer-Runner-0/INFO] [warpdrive]: [CC] Attaching warpdriveAirGenerator @ Spacheese (265 71 234) with 429:right
[07:57:44] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 1 opened
[07:57:45] [Server thread                  /INFO] [warpdrive]: [CC] IPeripheralProvider.getPeripheral @ Spacheese (265 71 234) east TileEntityAirGeneratorTiered '' @ Spacheese (265 71 234)
[07:57:49] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: Computer 2 placed
[07:57:50] [ComputerCraft-Computer-Runner-0/INFO] [warpdrive]: [CC] Attaching warpdriveAirGenerator @ Spacheese (265 71 234) with 430:left
[07:57:50] [Server thread                  /INFO] [warpdrive]: [CC] IPeripheralProvider.getPeripheral @ Spacheese (265 71 234) west TileEntityAirGeneratorTiered '' @ Spacheese (265 71 234)
[07:57:54] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 2 opened
[07:57:56] [ComputerCraft-Computer-Runner-0/INFO] [warpdrive]: [CC] Detaching warpdriveAirGenerator @ Spacheese (265 71 234) from 429:right
[07:57:56] [Server thread                  /INFO] [warpdrive]: [CC] IPeripheralProvider.getPeripheral @ Spacheese (265 71 234) east TileEntityAirGeneratorTiered '' @ Spacheese (265 71 234)
[07:58:00] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: Computer 1 broken
[07:58:02] [ComputerCraft-Computer-Runner-0/INFO] [warpdrive]: [CC] Detaching warpdriveAirGenerator @ Spacheese (265 71 234) from 430:left
[07:58:05] [Server thread                  /INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: Computer 2 broken

[08:00:29] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 1 placed
CCSGPeripheral.attach: to dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@277eba66
[08:00:34] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 1 opened
[08:00:39] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 2 placed
CCSGPeripheral.attach: to dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@ddba733
CCSGPeripheral.detach: from dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@277eba66
CCSGPeripheral.attach: to dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@1399973e
[08:00:45] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 2 opened
CCSGPeripheral.detach: from dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@1399973e
CCSGPeripheral.detach: from dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@ddba733
CCSGPeripheral.attach: to dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@3d7dda88
[08:00:51] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 1 broken
CCSGPeripheral.detach: from dan200.computercraft.core.apis.PeripheralAPI$PeripheralWrapper@3d7dda88
[08:00:56] [Server thread/INFO] [minecraft/DedicatedServer]: [SAW] Admin LemADEC: computer 2 broken

Long story short, we're not supposed to return a different interface for different sides of the same block. Consequently, SGCraft implementation of getPeripheral should cache previously created interfaces, or, just use the TileEntity itself as an interface or storage of the latest. For reference, getPeripheral() is called from the main thread so the World.getTileEntity() call is safe.

As for the original issue, I can't reproduce with 2.0.2 yet, so I can't confirm if the fix is effective.

Dockter commented 4 years ago

OK, this tells me the side change I made was incorrect; let me revert that and then have you try this again.

LemADEC commented 4 years ago

The revert commit did fix the NPE. There's still the attach/detach issue to be fixed, which was already present in 2.0.2.

Dockter commented 4 years ago

Did you test off of the most recent? Because I created a scheduled task on attach/detach that should have fixed that off-thread issue with SpongeForge. I need a new trace if in fact you did. If you pull and compile, it should compile as 2.0.4

LemADEC commented 4 years ago

As said earlier, I can't prove the fix is effective since I can't reproduce the issue with 2.0.2. In other words, I didn't see new occurrences with latest builds, but the issue might still be there.

Dockter commented 4 years ago

Curious, well I'm just going to consider this fixed then.