Crash with IC2, Base Minerals, Thermal Expansion, AE2 and Actually Additions

[dshadowwolf]

This crash was first spotted by one of our testers who also does some testing for Team CoFH. The difficulty in reliably reproducing it was recently solved when work was doing to find that the following list of mods - on Forge 12.18.3.2254 or 12.18.3.2221:

Actually Additions r104 or r105 Advanced Rocketry 1.1.1 Base Metals 2.5.0 beta1.55+ Base Minerals 2.5.0 beta1.10 CodeChicken Core 2.4.0.101 CodeChicken Lib 2.5.6.233 CoFHCore 4.1.0.155 IC2 2.6.173-ex110 LibVulpes 0.2.0 MMD OreSpawn 2.0.0.15 Thermal Expansion 5.0.3.86 Thermal Foundation 2.0.3.77

When starting a Server using the above selection, an error will trigger in Thermal Expansion where an item - from a support library inside Base Metals - is given two different wrappers and these wrappers hash differently, causing the GNU Trove code to crash.

Removing any mod from the listed set resolves the issue, as does changing Advanced Rocketry to the stable version (1.0.13 as of the last check of Curse). The fact that changing the version of Advanced Rocketry fixes the issue leads me to believe something in the code of 1.1.1 is broken badly. King Lemming has stated that this error is caused by a mod adding or changing stuff in the OreDictionary during the Post Init phase, but it might have a different cause.

[zmaster587]

Would it be at all possible to provide logs or a crash report so I can get a better sense of what is going on?

Also the only changes between 1.1.1 and 1.0.13 in the post init phase is the addition of a gravity handler being registered, the gravity controller machine being registered with the holoprojector, and loading of asteroid configuration. So I doubt it's an issue with something during AR's post init phase. LibVulpes also has not had it's post init phase touched at all for a long time.

[dshadowwolf]

None of them were much help - that mod-list was found through building up the inclusions one at a time. What I found truly odd was I tested that against the "stable" of Advanced Rocketry and got no crash, but with the Alpha the crash happens.

I've alerted you to this because none of us on the BaseMetals dev team can figure out what we could change to make this a non-issue and because it seems odd that it triggers only with the specific, specified version of Advanced Rocketry.

[zerotheliger]

Can you just listen to z and give us a crash report?mod dev cannot fix problem without that very important stack trace. Also could z get a release of base metals ? its 2.4 not 2.5 that we can find.

[zmaster587]

I tried building a test enviroment, however I cannot even find a build of Base Metals 2.5.0, nor even find any mods by the name of Base Minerals. Without a copy of all of the mods and without any kind of information as to the nature of the error there's I really have to go off of.

[dmodoomsirius]

Without a copy of the crash report there is nothing zmaster could do. Without a link to base metals 2.5.0 beta there is nothing zmaster could do. Does this happen with only libvulpus and advanced rocketry?

Sent from my iPhone

On Mar 14, 2017, at 8:24 PM, zmaster587 notifications@github.com wrote:

I tried building a test enviroment, however I cannot even find a build of Base Metals 2.5.0, nor even find any mods by the name of Base Minerals. Without a copy of all of the mods and without any kind of information as to the nature of the error there's I really have to go off of.

― You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

[zmaster587]

@dmodoomsirius He did mention it is an error stemming from thermal expansion and that "Removing any mod from the listed set resolves the issue", so I doubt it's AR alone if AR is part of the problem.

[dshadowwolf]

@dmodoomsirius As I'm a dev for BaseMetals and ModernMetals I understand entirely. The problem is that the crash log makes no sense and KingLemming swears that the cause is a mod playing in the Ore Dictionary during Post Init. However... the trigger is actually some strange cross-mod interaction within the list of mods I've given.

@zmaster587 I wish I could be more help, but I can't figure out why its occurring. You can find the entirety of the 2.5 series of BaseMetals and related development files at http://maven.mcmoddev.com/ in 'com.mcmoddev'

On a related note, I think the issue might be that Applied Energistics 2 actually does muck about in the Ore Dictionary in post and something about that list of mods causes things to slide about just enough to trigger the error. What really, really puzzles me is that you can change BaseMetals settings and the bug goes away and the error indicates a BaseMetals item as being the cause, but the error cannot be replicated until, as noted, the above list of mods is used.

Anyway... I need to get back to working on the TODO list for BaseMetals, rewriting "Lootable Bodies" to make it easier to maintain and try to get stuff for my personal projects rolling. Any insights you've got into whats happening or tools you know of that could help localize the actual cause would be appreciated. A cross-mod timing bug like this needs solved, if just for the players.

[zerotheliger]

Again give us a crash report otherwise nobody is going to be looking into this. We need info.... We need the crash reports. If your a mod dev you should know how important crash reports are....

[zmaster587]

I'll try again to build the test environment later. Although I am also obliged to mention that I have very little time to work on stuff lately and it is rather inconvient for me to have to spend 15 minutes setting up a test bench to generate a crash dump you already have. I also feel I should remind you that you are reporting this as a bug to me here, not kinglemming.

I understand that the crash report may seem confusing, but I must impress upon you that the info you've given me is equivalent to me coming to you and saying "base metals is crashing due to a hashing error somewhere, cpw says it might be related to registering a block in post init, I am withholding the crash dump as it is confusing. Oh and it only happens with an exact set of [insert 10 mods here]".

Be that as it may, I am hoping to get an hour of time between work and sleep (6 hours is good) tonight when I will try to test this.

Also I would suggest to test your theory you can put a print statement in the ore registration event. Then just look for ore regustation in the logs after post init.

[zerotheliger]

All you have really told us is its broken.. Ok well if we had reports we can figure out a lead to see why its broken. Otherwise telling us basicly its broken and to fix it wont get us anywhere without a crash report.

[dshadowwolf]

Sorry, let me put it this way: The crash report doesn't even hint at what is actually happening. I'm not even sure that the one means we found of reliably reproducing it with a minimal set of mods is the only method.

I filed this to alert the dev team here that this was occurring so they'd know if someone came to them reporting similar - I have a very bad feeling that this is one of those bugs that would take every dev team from all indicated mods working together to actually find the cause - and after the interactions I've had with King Lemming I cannot see that happening.

The biggest reason I brought it to your attention was that it does not occur for me - or anyone that has tested this - with your current stable, only the alpha release. This could, very likely, be exactly because the alpha has the added code which is causing the timing to hit perfectly - I really do not know and have not been able to figure it out. (and I've been working on this since first reported to me by the tester who discovered the bug a week ago... I've almost given up, because it makes no sense! 'Turn off this bit of config in this mod and the bug disappears', 'take out this mod and the bug disappears', 'change the version of this mod and the bug disappears' - it's gotten to the point that I'm sick of looking at code trying to figure out why it is occurring)

[zmaster587]

Unless there's mutlithreaded loading going on there shouldn't be any timing involved. However it might be possible that the mod load order has changed (I'm not familar with the exactly algorithm forge uses to determine load order so it's a bit of a pot shot). Anyway, I just got off work and I'll try sticking a test bench together to see if I can peice it together.

[zmaster587]

The crash occurs at the "serverAboutToStart" phase, so there's no reason adding an oredict entry in post init would do this. I have also confirmed that at least one of the culprits is "dustNickel". There appears to be two items, one that is registered to the ore dictionary and one that is not. Both objects however are type "com.mcmoddev.lib.item.ItemMetalPowder".

Essentially it's saying there are two instances of itemstack (ItemMetalPowder , meta:0), one has the forge ore id of 691, the other does not have an oreID.

Procedure: From the stack trace generated on launch: Object 1: ... hashCode= 691 ... m:0 i:com.mcmoddev.lib.item.ItemMetalPowder Object 2: ... hashCode= 348454912 ... m:0 i:com.mcmoddev.lib.item.ItemMetalPowder

Also given: "public int hashCode() { return this.oreID != -1 ? this.oreID : super.hashCode(); }" --from ComparableItemStack in COFH core we can determine if an oredict entry exists for the item then the hash is the oredict number.

Also given the fact super.hasCode is "return this.metadata & 0xFFFF | getId() << 16;" we can deterimine the itemID which I've determined to be 5317 by taking 348454912 = 0x14C50000 >> 16 => 14C5 = 5317 (will likely differ on your world due to forge's item id mapping)

Because the hashcode is the oreID in the comparableItem stack class means I can do "logger.fatal("########################" + OreDictionary.getOreName(691) + "##############################");" to print out the item's ore name. "########################dustNickel##############################"

The code: "Item item = Item.getItemById(5317); logger.fatal(item.getUnlocalizedName());" yields "item.basemetals.nickel_powder"

Findings

I can also confirm changing "B:EnableNickel=true" => "B:EnableNickel=false" in the BaseMetals.cfg file allows the world to load properly. Oddly enough disabling IC2 support also allows the game to load even with nickel enabled

I've also discovered that of the mods listed, only Thermal foundation and BaseMetals reference nickel explicitly.

Also by printing in the ore registration event I can confirm the last ore registration occurs in the init phase with Thermal Foundation registering rockWool. Using the same printout I can confirm only ThermalFoundation and BaseMetals register dustNickel

That's about as far as I've got right now.

[dshadowwolf]

Yep. You've gotten a touch farther than I had, but the results you've found are about what I expected.

And thanks for this - I'm going to go take a look through BaseMetals again and see if we actually do have a double-registry/single-oredict thing happening or if that is some kind of artifact (perhaps the "small pile of nickel dust")

Okay... having re-checked the source... there appears to be something strange going on. Any ItemMetalPowder in BaseMetals gets created in one of two wrapper functions - either 'createItemsBasic' or 'createItemsFull' in com.mcmoddev.lib.init.Items and there is only one place where this would be true for Nickel.

Against my better judgement, I'm building a test version that moves a single function call - maintained for backwards compatibility - to see about making sure that it isn't Java itself being derpy and causing this issue.

Okay... I'm completely out of ideas. There was one possibility that I thought of and had reasons why it wasn't that immediately - we have a compat namespace we're keeping around for the next release to give some potentially unknown modders who might have had a dependency on BaseMetals a break - but if it was that, there would be more issues.

[zmaster587]

Thos can probably be much more easily solved by injecting a trace printout in the method responsible for adding items to the registration list for the furnace. From there we can know exactly where the addition is made

[zerotheliger]

Next time i dont care how confusing the crash report is give it to us because otherwise its a waste of time trying to collect info you already have.

[zerotheliger]

We have busy lives and cant afford to spend the time debugging to generate a crash report that already exists in this case it helped us

[zmaster587]

@zerotheliger I think that's been said enough times, please chill

[zmaster587]

Something else odd I just found is that nickel powder, the itemstack registered for the furnace recipes, does not appear to have an ore dictionary entry associated with it, however previous dumps indicate there also exists an item stack with the same item registered in the ore dictionary, so that does indicate two versions of the itemstack are floating around.

I've already dumped the furnace recipe list, now Ima try pulling oredict names for any ItemStack(getItem, 1, 0) and see if that differs using the follwing

@EventHandler

    public void serverStarted(FMLLoadCompleteEvent event) {
        for(ItemStack stack : FurnaceRecipes.instance().getSmeltingList().keySet()) {
            logger.fatal(stack + "=>" + FurnaceRecipes.instance().getSmeltingList().get(stack));
            String orenames = "";
            for( int i : OreDictionary.getOreIDs(stack))
                orenames += " " + OreDictionary.getOreName(i);
            logger.fatal(orenames == "" ? "No Ores" : orenames);

            orenames = "";
            for( int i : OreDictionary.getOreIDs(new ItemStack(stack.getItem())))
                orenames += " " + OreDictionary.getOreName(i);
            logger.fatal("Ore 2: " + orenames == "" ? "No Ores" : orenames);
        }
    }

[zmaster587]

O have discovered that a majority of basemetal's items have furnace itemstack recipe entries that do not have ore dictionary matching, but the new ItemStack(getItem,1,0) does.

This can occur if you're using metadata to store multiple types per item, but given the names like nickel_powder I assume this is not the case. This could very easily result in two versions of the item floating around, one pulled the the furnace recipe handler (Thermal expansion does do this) and a version of dustNickel pulled from the ore dictionary registered to the same item (different item count/meta/NBT?).

I've got a dump here. print style is as such: ... source itemstack=>result itemstack ore dict entries of the source itemsstack ore dict entries of ItemStack(sourceItemStack.getItem()) (implicity size 1, meta 0) ... temp.txt

As a note: ore dict entries where the metadata of an item is used to determine the material is screwy for the second entry.

[zmaster587]

I think I just found your problem. If you register an item as a furnace input rather than an item stack it is registered as such:

    public void addSmelting(Item input, ItemStack stack, float experience)
    {
        this.addSmeltingRecipe(new ItemStack(input, 1, 32767), stack, experience);
    }

unfortunately 32767 is not 0 and the oredictionary is meta sensative

So if you have your oredictionary entry as ItemStack(Item_Nickel_powder, 1, 0) or equivilently ItemStack(Item_Nickel_powder), you suddenly can have two variations floating around if a furnace loads oredict dust -> ingot AND explicitly registered furnace recipes.

So my advice would be to try changing lines containing " GameRegistry.addSmelting(material.powder, new ItemStack(material.ingot, 1), oreSmeltXP);"

to " GameRegistry.addSmelting(new ItemStack(material.powder), new ItemStack(material.ingot, 1), oreSmeltXP);"

This will make sure the recipe registered to the furnace recipe registry contains the ore dictionaried version of the material

[dshadowwolf]

hrm... changed all smelting registrations to not use the raw item - and thanks for this hint, if it works I'm going to credit you, @zmaster587 and your whole team for the fix. It's the least I can do.

(five minutes later) And... no change.

[zmaster587]

would you be able to toss me a build of the mod with the recipes changed for me to test with?

[dshadowwolf]

Not a problem. I'll attach it here... BaseMetals-1.10.2-2.5.0-beta1.jar.zip

Just remove the '.zip' - I stuck that on to get around GH's restrictions when I remembered that Jar's are already zip-files.

[zmaster587]

Alright, thanks! will do

[zmaster587]

I tested it with the new build and found that it still crashed and outputted the same dump for the recipes as I had linked earlier. I also opened up the file to check to make sure the code had been changed and found that it had not.

com.mcmoddev.lib.init.Recipes.class:195 still has the line "GameRegistry.addSmelting(material.powder, new ItemStack(material.ingot, 1), oreSmeltXP);" in BaseMetals-1.10.2-2.5.0.beta1.jar. Which is where I think this problem is coming from.

[dshadowwolf]

huh... I changed the code to not have that... let me make sure the "./gradlew clean" actually goes through.

facepalm Turns out that my script for copying stuff over to the dev environment had a typo that was dropping the new jar in the wrong directory

But... same crash. And just PR'd the recipe change just for future proofing, as @jriwanek remembers something similar to this causing issues in the version of Mariculture in the ReGrowth pack back in 1.7

[dshadowwolf]

Okay, with the recipe fix (thanks for that hint) and using a variation on your furnace recipe dump (I have come to habitually loop a maps entrySet() instead of its keySet() - YMMV) things are now showing as I'd expect them to in the ore dictionary.

[17:14:11] [Server thread/FATAL] [basemetals/basemetals]: 1xitem.basemetals.nickel_powder@0 => 1xitem.basemetals.nickel_ingot@0
[17:14:11] [Server thread/FATAL] [basemetals/basemetals]: Ore 1:  dustNickel
[17:14:11] [Server thread/FATAL] [basemetals/basemetals]: Ore 2:  dustNickel

However, the issue persists. I have no more ideas now than I did, but had hoped this change would work. Perhaps I should spread the recipe change further...

[dshadowwolf]

Alright. I have no more ideas - I've traced the BaseMetals code, I've dumped the furnace recipe list, I've dumped the entire ore dictionary... About all I can think is that there is something strange going on in the CoFHCore "Comparable" wrapper class.

[zmaster587]

Mind tossing me an updated build to work with? Maybe I can find something?

[dshadowwolf]

Most up-to-date is now on the Maven - this one includes the changes to the recipe code you suggested. http://maven.mcmoddev.com/ (in com.mcmoddev) (and a commented-out version of your code for dumping the furnace recipes and some code for dumping the ore dictionary itself)

[zmaster587]

Doesn't appear the change had any effect on the error.. same two hashes and items

Looks like Thermal expansion loads default recipes (which includes dustNickel and would add the first recipe) first thing is post init.

I kinda stumped on this one... Just going to resummarize becuase it's a long thread:

• Crash caused by the nickel_powder ("dustNickel")
• Crash does not occur with IC2 compat turned off
• Crash only appears with the set of mods listed in the first post
• Crash appears only with the unstable version of Advanced Rocketry

[dshadowwolf]

Yeah - I think something is going on in a background thread and the specific timing of various threads (and the determinism of Java's threading) is causing this. But what, exactly, is going on is beyond me. The only thing I can think of would be to try moving the TE integration of BaseMetals from running during preInit to running during Init - which, thankfully, is not that hard.

On Wed, Mar 22, 2017 at 12:25 AM, zmaster587 notifications@github.com wrote:

Doesn't appear the change had any effect on the error.. same two hashes and items

Looks like Thermal expansion loads default recipes (which includes dustNickel and would add the first recipe) first thing is post init.

I kinda stumped on this one...

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/zmaster587/AdvancedRocketry/issues/456#issuecomment-288295236, or mute the thread https://github.com/notifications/unsubscribe-auth/AAS_okasQllrMCbJRfnWEZqidleMPQYJks5roKKogaJpZM4MbGip .

[zmaster587]

I'm fairly sure it's not a threadin problem. Minecraft only uses one thread to load (can be verified with a debugger). Also generally problems involving threading timing occur seemingly at random and you can launch the program with the same settings and sometimes it'll break sometimes it won't.

That being said I think you're probably correct about it being a load order issue, though I think it's due to mod load order determined by forge.

[zmaster587]

You could try moving it, if it fixes it then that's just more information about the nature of the problem and may lead to nailing down an exact cause

[zmaster587]

Fairly sure it's not an AR issue, so closing

[dshadowwolf]

Have managed to (accidentally) find a related crash where the item causing the trigger is from Vanilla. This now appears to be, wholly, a timing bug of some sort in the TE code. Not an AR - or any other possibly indicated mod - issue at all.