MovingBlocks / Terasology

Terasology - open source voxel world
http://terasology.org
Apache License 2.0
3.65k stars 1.33k forks source link

World loading sequence issue? WoodAndStone/AnotherWorld #893

Closed Cervator closed 10 years ago

Cervator commented 10 years ago

So I've been playing with the crash bug on world load when WoodAndStone and its unique world is enabled. It happens inconsistently and I think I got a log batch that looks useful:

00:57:51.659 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered Block Core:Torch.FRONT with id 111
00:57:51.659 [main] INFO  o.t.w.b.internal.BlockManagerImpl - Registered Block Core:Torch.BACK with id 112
Unexpected exception
java.security.AccessControlException: Module class 'org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition' calling into 'org.terasology.world.block.internal.BlockManagerImpl' requiring permission '("java.lang.RuntimePermission" "accessClassInPackage.sun.reflect")'
    at org.terasology.engine.module.ModuleSecurityManager.checkAPIPermissionsFor(ModuleSecurityManager.java:183)
    at org.terasology.engine.module.ModuleSecurityManager.checkModAccess(ModuleSecurityManager.java:164)
    at org.terasology.engine.module.ModuleSecurityManager.checkPermission(ModuleSecurityManager.java:193)
    at java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1529)
    at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:305)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    at ch.qos.logback.classic.spi.PackagingDataCalculator.<clinit>(PackagingDataCalculator.java:42)
    at ch.qos.logback.classic.spi.ThrowableProxy.getPackagingDataCalculator(ThrowableProxy.java:135)
    at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:144)
    at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:129)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439)
    at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:432)
    at ch.qos.logback.classic.Logger.error(Logger.java:550)
    at org.terasology.world.block.loader.BlockLoader.loadWithShape(BlockLoader.java:194)
    at org.terasology.world.block.internal.BlockManagerImpl.getBlockFamily(BlockManagerImpl.java:332)
    at org.terasology.world.block.internal.BlockManagerImpl.getBlock(BlockManagerImpl.java:363)
    at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.getBlock(AdvancedLSystemTreeDefinition.java:254)
    at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.generateTree(AdvancedLSystemTreeDefinition.java:100)
    at org.terasology.plantPack.PineGrowthDefinition.generatePlant(PineGrowthDefinition.java:129)
    at org.terasology.gf.generator.BlockFloraSpawnDefinition.generatePlant(BlockFloraSpawnDefinition.java:72)
    at org.terasology.gf.generator.FloraFeatureGenerator.generateInChunk(FloraFeatureGenerator.java:108)
    at org.terasology.anotherWorld.PluggableWorldGenerator.applySecondPass(PluggableWorldGenerator.java:128)
    at org.terasology.world.chunks.pipeline.SecondPassChunkTask.enact(SecondPassChunkTask.java:56)
    at org.terasology.utilities.concurrency.TaskProcessor.run(TaskProcessor.java:50)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)
00:57:53.509 [main] ERROR o.terasology.engine.TerasologyEngine - Uncaught exception
java.lang.IndexOutOfBoundsException: Index: 3, Size: 3
    at java.util.ArrayList.rangeCheck(ArrayList.java:635) ~[na:1.7.0_45]
    at java.util.ArrayList.get(ArrayList.java:411) ~[na:1.7.0_45]
    at com.bulletphysics.$Stack.get$javax$vecmath$Quat4f(Unknown Source) ~[tera-bullet-1.0.0.jar:na]
    at com.bulletphysics.linearmath.QuaternionUtil.quatRotate(QuaternionUtil.java:82) ~[tera-bullet-1.0.0.jar:na]
    at org.terasology.logic.location.LocationComponent.getWorldPosition(LocationComponent.java:104) ~[classes/:na]
    at org.terasology.logic.location.LocationComponent.getWorldPosition(LocationComponent.java:96) ~[classes/:na]
    at org.terasology.world.chunks.internal.ChunkRelevanceRegion.calculateCenter(ChunkRelevanceRegion.java:130) ~[classes/:na]
    at org.terasology.world.chunks.internal.ChunkRelevanceRegion.update(ChunkRelevanceRegion.java:108) ~[classes/:na]
    at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.updateRelevance(LocalChunkProvider.java:341) ~[classes/:na]
    at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.update(LocalChunkProvider.java:249) ~[classes/:na]
    at org.terasology.rendering.world.WorldRenderer.pregenerateChunks(WorldRenderer.java:1145) ~[classes/:na]
    at org.terasology.engine.modes.loadProcesses.PrepareWorld.step(PrepareWorld.java:42) ~[classes/:na]
    at org.terasology.engine.modes.StateLoading.update(StateLoading.java:211) ~[classes/:na]
    at org.terasology.engine.TerasologyEngine.mainLoop(TerasologyEngine.java:499) ~[classes/:na]
    at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:229) ~[classes/:na]
    at org.terasology.engine.Terasology.main(Terasology.java:68) ~[classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_45]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_45]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_45]
    at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_45]
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120) ~[idea_rt.jar:na]
00:57:53.518 [Chunk-Generator-1] ERROR o.t.world.block.loader.BlockLoader - Error loading block shape PlantPack:PineLeaf
java.lang.IndexOutOfBoundsException: Index: 2, Size: 3
    at java.util.ArrayList.rangeCheck(ArrayList.java:635) ~[na:1.7.0_45]
    at java.util.ArrayList.get(ArrayList.java:411) ~[na:1.7.0_45]
    at com.bulletphysics.$Stack.get$javax$vecmath$Quat4f(Unknown Source) ~[na:na]
    at com.bulletphysics.linearmath.QuaternionUtil.quatRotate(QuaternionUtil.java:82) ~[na:na]
    at org.terasology.world.block.shapes.BlockMeshPart.rotate(BlockMeshPart.java:116) ~[na:na]
    at org.terasology.world.block.loader.BlockLoader.createAppearance(BlockLoader.java:371) ~[na:na]
    at org.terasology.world.block.loader.BlockLoader.constructSingleBlock(BlockLoader.java:271) ~[na:na]
    at org.terasology.world.block.loader.BlockLoader.loadWithShape(BlockLoader.java:186) ~[na:na]
    at org.terasology.world.block.internal.BlockManagerImpl.getBlockFamily(BlockManagerImpl.java:332) ~[na:na]
    at org.terasology.world.block.internal.BlockManagerImpl.getBlock(BlockManagerImpl.java:363) ~[na:na]
    at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.getBlock(AdvancedLSystemTreeDefinition.java:254) ~[na:na]
    at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.generateTree(AdvancedLSystemTreeDefinition.java:100) ~[na:na]
    at org.terasology.plantPack.PineGrowthDefinition.generatePlant(PineGrowthDefinition.java:129) ~[na:na]
    at org.terasology.gf.generator.BlockFloraSpawnDefinition.generatePlant(BlockFloraSpawnDefinition.java:72) ~[na:na]
    at org.terasology.gf.generator.FloraFeatureGenerator.generateInChunk(FloraFeatureGenerator.java:108) ~[na:na]
    at org.terasology.anotherWorld.PluggableWorldGenerator.applySecondPass(PluggableWorldGenerator.java:128) ~[na:na]
    at org.terasology.world.chunks.pipeline.SecondPassChunkTask.enact(SecondPassChunkTask.java:56) ~[na:na]
    at org.terasology.utilities.concurrency.TaskProcessor.run(TaskProcessor.java:50) ~[na:na]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_45]
    at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_45]
00:57:53.519 [Chunk-Generator-1] WARN  o.t.w.b.internal.BlockManagerImpl - Unable to resolve block family PlantPack:PineLeaf
00:57:53.520 [Chunk-Generator-1] INFO  o.t.w.b.internal.BlockManagerImpl - Registered BlockFamily[PlantPack:PineLeaf]
00:57:53.522 [Chunk-Generator-1] INFO  o.t.w.b.internal.BlockManagerImpl - Registered Block PlantPack:PineLeaf with id 113

Odd that there is a permission issue in there since the game can fully load a usable world for WaS. I suspect the later issue involving TeraBullet is a red herring (although it could be an issue on its own) caused by something happening out of sequence during world load / block registration. There is plant generation happening in there too, probably part of the issue?

Going to need @MarcinSc and @immortius to help figure this one out :-)

immortius commented 10 years ago

Well, the permission exception seems to be from the logger doing something

On 1 February 2014 17:26, Rasmus Praestholm notifications@github.comwrote:

So I've been playing with the crash bug on world load when WoodAndStone and its unique world is enabled. It happens inconsistently and I think I got a log batch that looks useful:

00:57:51.659 [main] INFO o.t.w.b.internal.BlockManagerImpl - Registered Block Core:Torch.FRONT with id 111 00:57:51.659 [main] INFO o.t.w.b.internal.BlockManagerImpl - Registered Block Core:Torch.BACK with id 112 Unexpected exception java.security.AccessControlException: Module class 'org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition' calling into 'org.terasology.world.block.internal.BlockManagerImpl' requiring permission '("java.lang.RuntimePermission" "accessClassInPackage.sun.reflect")' at org.terasology.engine.module.ModuleSecurityManager.checkAPIPermissionsFor(ModuleSecurityManager.java:183) at org.terasology.engine.module.ModuleSecurityManager.checkModAccess(ModuleSecurityManager.java:164) at org.terasology.engine.module.ModuleSecurityManager.checkPermission(ModuleSecurityManager.java:193) at java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1529) at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:305) at java.lang.ClassLoader.loadClass(ClassLoader.java:358) at ch.qos.logback.classic.spi.PackagingDataCalculator.(PackagingDataCalculator.java:42) at ch.qos.logback.classic.spi.ThrowableProxy.getPackagingDataCalculator(ThrowableProxy.java:135) at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:144) at ch.qos.logback.classic.spi.LoggingEvent.(LoggingEvent.java:129) at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:439) at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:432) at ch.qos.logback.classic.Logger.error(Logger.java:550) at org.terasology.world.block.loader.BlockLoader.loadWithShape(BlockLoader.java:194) at org.terasology.world.block.internal.BlockManagerImpl.getBlockFamily(BlockManagerImpl.java:332) at org.terasology.world.block.internal.BlockManagerImpl.getBlock(BlockManagerImpl.java:363) at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.getBlock(AdvancedLSystemTreeDefinition.java:254) at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.generateTree(AdvancedLSystemTreeDefinition.java:100) at org.terasology.plantPack.PineGrowthDefinition.generatePlant(PineGrowthDefinition.java:129) at org.terasology.gf.generator.BlockFloraSpawnDefinition.generatePlant(BlockFloraSpawnDefinition.java:72) at org.terasology.gf.generator.FloraFeatureGenerator.generateInChunk(FloraFeatureGenerator.java:108) at org.terasology.anotherWorld.PluggableWorldGenerator.applySecondPass(PluggableWorldGenerator.java:128) at org.terasology.world.chunks.pipeline.SecondPassChunkTask.enact(SecondPassChunkTask.java:56) at org.terasology.utilities.concurrency.TaskProcessor.run(TaskProcessor.java:50) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) 00:57:53.509 [main] ERROR o.terasology.engine.TerasologyEngine - Uncaught exception java.lang.IndexOutOfBoundsException: Index: 3, Size: 3 at java.util.ArrayList.rangeCheck(ArrayList.java:635) ~[na:1.7.0_45] at java.util.ArrayList.get(ArrayList.java:411) ~[na:1.7.0_45] at com.bulletphysics.$Stack.get$javax$vecmath$Quat4f(Unknown Source) ~[tera-bullet-1.0.0.jar:na] at com.bulletphysics.linearmath.QuaternionUtil.quatRotate(QuaternionUtil.java:82) ~[tera-bullet-1.0.0.jar:na] at org.terasology.logic.location.LocationComponent.getWorldPosition(LocationComponent.java:104) ~[classes/:na] at org.terasology.logic.location.LocationComponent.getWorldPosition(LocationComponent.java:96) ~[classes/:na] at org.terasology.world.chunks.internal.ChunkRelevanceRegion.calculateCenter(ChunkRelevanceRegion.java:130) ~[classes/:na] at org.terasology.world.chunks.internal.ChunkRelevanceRegion.update(ChunkRelevanceRegion.java:108) ~[classes/:na] at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.updateRelevance(LocalChunkProvider.java:341) ~[classes/:na] at org.terasology.world.chunks.localChunkProvider.LocalChunkProvider.update(LocalChunkProvider.java:249) ~[classes/:na] at org.terasology.rendering.world.WorldRenderer.pregenerateChunks(WorldRenderer.java:1145) ~[classes/:na] at org.terasology.engine.modes.loadProcesses.PrepareWorld.step(PrepareWorld.java:42) ~[classes/:na] at org.terasology.engine.modes.StateLoading.update(StateLoading.java:211) ~[classes/:na] at org.terasology.engine.TerasologyEngine.mainLoop(TerasologyEngine.java:499) ~[classes/:na] at org.terasology.engine.TerasologyEngine.run(TerasologyEngine.java:229) ~[classes/:na] at org.terasology.engine.Terasology.main(Terasology.java:68) ~[classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_45] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_45] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_45] at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_45] at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120) ~[idea_rt.jar:na] 00:57:53.518 [Chunk-Generator-1] ERROR o.t.world.block.loader.BlockLoader - Error loading block shape PlantPack:PineLeaf java.lang.IndexOutOfBoundsException: Index: 2, Size: 3 at java.util.ArrayList.rangeCheck(ArrayList.java:635) ~[na:1.7.0_45] at java.util.ArrayList.get(ArrayList.java:411) ~[na:1.7.0_45] at com.bulletphysics.$Stack.get$javax$vecmath$Quat4f(Unknown Source) ~[na:na] at com.bulletphysics.linearmath.QuaternionUtil.quatRotate(QuaternionUtil.java:82) ~[na:na] at org.terasology.world.block.shapes.BlockMeshPart.rotate(BlockMeshPart.java:116) ~[na:na] at org.terasology.world.block.loader.BlockLoader.createAppearance(BlockLoader.java:371) ~[na:na] at org.terasology.world.block.loader.BlockLoader.constructSingleBlock(BlockLoader.java:271) ~[na:na] at org.terasology.world.block.loader.BlockLoader.loadWithShape(BlockLoader.java:186) ~[na:na] at org.terasology.world.block.internal.BlockManagerImpl.getBlockFamily(BlockManagerImpl.java:332) ~[na:na] at org.terasology.world.block.internal.BlockManagerImpl.getBlock(BlockManagerImpl.java:363) ~[na:na] at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.getBlock(AdvancedLSystemTreeDefinition.java:254) ~[na:na] at org.terasology.gf.tree.lsystem.AdvancedLSystemTreeDefinition.generateTree(AdvancedLSystemTreeDefinition.java:100) ~[na:na] at org.terasology.plantPack.PineGrowthDefinition.generatePlant(PineGrowthDefinition.java:129) ~[na:na] at org.terasology.gf.generator.BlockFloraSpawnDefinition.generatePlant(BlockFloraSpawnDefinition.java:72) ~[na:na] at org.terasology.gf.generator.FloraFeatureGenerator.generateInChunk(FloraFeatureGenerator.java:108) ~[na:na] at org.terasology.anotherWorld.PluggableWorldGenerator.applySecondPass(PluggableWorldGenerator.java:128) ~[na:na] at org.terasology.world.chunks.pipeline.SecondPassChunkTask.enact(SecondPassChunkTask.java:56) ~[na:na] at org.terasology.utilities.concurrency.TaskProcessor.run(TaskProcessor.java:50) ~[na:na] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_45] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_45] at java.lang.Thread.run(Thread.java:744) ~[na:1.7.0_45] 00:57:53.519 [Chunk-Generator-1] WARN o.t.w.b.internal.BlockManagerImpl - Unable to resolve block family PlantPack:PineLeaf 00:57:53.520 [Chunk-Generator-1] INFO o.t.w.b.internal.BlockManagerImpl - Registered BlockFamily[PlantPack:PineLeaf] 00:57:53.522 [Chunk-Generator-1] INFO o.t.w.b.internal.BlockManagerImpl - Registered Block PlantPack:PineLeaf with id 113

Odd that there is a permission issue in there since the game can fully load a usable world for WaS. I suspect the later issue involving TeraBullet is a red herring (although it could be an issue on its own) caused by something happening out of sequence during world load / block registration. There is plant generation happening in there too, probably part of the issue?

Going to need @MarcinSc https://github.com/MarcinSc and @immortiushttps://github.com/immortiusto help figure this one out :-)

Reply to this email directly or view it on GitHubhttps://github.com/MovingBlocks/Terasology/issues/893 .

Cervator commented 10 years ago

I was curious to see if the seed would impact this issue (thinking maybe more trees very close to the player could trigger the issue but normal chunks would spend enough time for the sequence issue to pass) - but while "2" worked first try after I ran that world once "1" (which failed first try) then worked ... even with a new binary download from develop (with the two split out modules now included)

Also fixed tiny needed tweaks for that ItemComponent.name thing while I was testing around.

Cervator commented 10 years ago

@immortius - I noticed commits to TeraBullet, but it doesn't build automatically in Jenkins and I'm not sure it gets uploaded to Artifactory either - how far did you go with testing it? Any chance it might help this?

immortius commented 10 years ago

It should address this, although the may be a big performance hit. JBullet uses a byte code post processor to allow it to put certain variables on the stack - the error seems to be coming from this code. So I removed this - I hope the Java 7 gc improvements make up for this.

I haven't tested it at all yet.

Cervator commented 10 years ago

Closing from age / likely fixed as I haven't seen it for ages. Also reshuffling world gen soon which is bound to impact this if it still exists.