mezz / JustEnoughItems

Item and Recipe viewing mod for Minecraft
https://www.curseforge.com/minecraft/mc-mods/jei
MIT License
778 stars 303 forks source link

Load times doubled with .329 #538

Closed BSKCorp closed 7 years ago

BSKCorp commented 7 years ago

When the initial loading with .329 is about double in Phase 3; Post Init.; Adding ItemStack Ingredients then previous version. I want to say it takes about 1 full minute or so to complete that section. Compared to .328 were the load time is half of that, maybe more. (did not run a timer.) Not sure if this is a bug or intentional.

mezz commented 7 years ago

Thanks for the report!

The only thing that changed here is that JEI loads on PostInit instead of when you are joining a world. So before, it was not showing a progress bar at all.

It should probably not take 1 full minute to complete that section though, please check your log for errors.

NoobTaco commented 7 years ago

@mezz I can confirm this long load time with EnderIO also installed. ALSO. . Any version after version 328 has stopped showing alloy recipes with the U menu.

Example.. . Look up Dark Steel. . There is no way to get the smelting recipe. With version 328 and before you could look up the recipe.

Something is wrong with the new system. I am trying to narrow it down.

Thanks for your great mod

LightningLdr180 commented 7 years ago

I can also confirm that load times are significantly longer, as well as the missing recipes @NoobTaco has reported. Similarly the recipes for Mekanism also no longer show up.

mezz commented 7 years ago

If you are missing recipes, be sure to update Reliquary. If you don't have Reliquary, please paste your client log to https://gist.github.com and link it here.

NoobTaco commented 7 years ago

The slow down is on Adding ItemStack ingredients. I have 6542 items and its crawling.

My log is here. https://gist.github.com/NoobTaco/1a3a1e217fc9b875b56e138e4984b6d2

mezz commented 7 years ago

Bar Finished: Adding ItemStack ingredients. took 114.396s

Yeah that's taking waaay too long. Can you link me to the mod pack you're using so I can take a look?

mezz commented 7 years ago

@NoobTaco Can you link me to the mod pack you're using so I can take a look?

NoobTaco commented 7 years ago

@mezz You bet. It's my own mod pack. https://minecraft.curseforge.com/projects/shadowlands-basic-mods

mezz commented 7 years ago

@NoobTaco Hmm I tried with the version of your pack before you reverted JEI. When I run it there's no problem with loading time.

[JEI]: Built item filter in 580 ms

Your log shows a much much longer time:

[JEI/JEI]: Built item filter in 114412 ms

Try increasing the amount of memory you give to Java. Maybe the memory is at its limit during loading and JEI is pushing it over the edge.

NoobTaco commented 7 years ago

Well, pushed it to 12 gigs and its still taking a while.

I am not as concerned about the load time as the missing recipes myself. But both fixed would be wonderful.

It is still running the load as I write this update hehe

mezz commented 7 years ago

Releasing JEI 3.13.0.332 to fix the missing recipes. Still not sure what the long delay is for.

NoobTaco commented 7 years ago

Will test it out as soon as it hits the site.

mezz commented 7 years ago

It's up on Curse now

NoobTaco commented 7 years ago

Tested and recipe's are working. I do still have the long load but at least one thing is working.

Thanks @mezz

iTraumatik commented 7 years ago

Having the long load times also with JEI 329+. I havent played for approx 2 weeks and just updated these mods.... FEI, AbyssalCraft, Baubbles, EnviroTech, Valkyrelib, PressurePipes, Bdlib, Gendustry, ExtraUtils2, Forestry, Quark, Botania, ExtraAlchemy, TheOneProbe, McFlux, InventoryTweaks, JER, WuestUtils, Reliquary, Llibrary, ExtremeReactors, Tesla, ZeroCore, RFTools, MysticalAgriculture, BloodMagic, GuideAPI, Hatchery, Railcraft, FiresRandomThings, MalasisCore, PamsHarvest, RFToolsCtrl, MCjitylib. It slows to crawl at 6/7, Adding ItemStack ingredients 20,948. [17:33:53] [Client thread/INFO]: Built item filter in 620496 ms. 180 mods total in My own pack that isnt on any sites. Tried upping Java from 6k to 8k (says using 5200 to 5999 onscreen in game.) and doesnt help Java 8 101 installed, have installed on Samsung 850pro SSD. Just hoping this will help, might be another mod.

mezz commented 7 years ago

I set my memory down to just 2GB and it still loaded swiftly, so that's not the problem at all.

Does the progress bar stick at a specific point, or does it make steady progress through the items?

NoobTaco commented 7 years ago

It does make a steady progress through. I captured the load screen so you can get a feel for it.

https://youtu.be/U9ZIDK0T84Y

iTraumatik commented 7 years ago

sry just woke, It is a steady increase also here. I also tried with different forge versions from 2099 up with same result. I noticed in latest log "[23:11:43] [Client thread/INFO]: Extra Utilities 2 JEI Plugin - ACTIVATE!" not sure if they were in last version of ExtraUtilities2 or not and EX2.cfg doesnt mention them. Line 4505 "[23:13:01] [Client thread/ERROR]: Null item in itemStack java.lang.NullPointerException" My log is too long for pastebin, let me know if need and how to post. Thanks again. Edit . took out EX2 and same load times.

mezz commented 7 years ago

@NoobTaco I see you have a texture pack that's not in your modpack, and also Optifine. What version of the texture pack are you using? Do you have JEI Color Search enabled?

mezz commented 7 years ago

Hmm even with the texture pack and color search, the item filter still loaded in under 1 second for me.

mezz commented 7 years ago

It's Optifine. Really didn't expect that.

NoobTaco commented 7 years ago

@mezz lol I had JUST finished testing and finding that out and was on my way to report when I saw your email pop up.

It is Optifine. .

mezz commented 7 years ago

Doing some profiling so I can make a proper report. In the meantime just remove Optifine or endure the long startup.

iTraumatik commented 7 years ago

Can confirm that it isnt optifine in my pack. I took it out and its on my desktop. Oh and no texture pack / resource pack @mezz [15:48:44] [Client thread/ERROR]: Null item in itemStack java.lang.NullPointerException at mezz.jei.util.StackHelper.getSubtypes(StackHelper.java:218) [StackHelper.class:?] at mezz.jei.util.StackHelper.getAllSubtypes(StackHelper.java:292) [StackHelper.class:?] at mezz.jei.util.StackHelper.getAllSubtypes(StackHelper.java:270) [StackHelper.class:?] at mezz.jei.plugins.vanilla.ingredients.ItemStackHelper.expandSubtypes(ItemStackHelper.java:24) [ItemStackHelper.class:?] at mezz.jei.util.Ingredients.setInputs(Ingredients.java:48) [Ingredients.class:?] at mezz.jei.plugins.vanilla.crafting.ShapedRecipesWrapper.getIngredients(ShapedRecipesWrapper.java:29) [ShapedRecipesWrapper.class:?] at mezz.jei.RecipeRegistry.addRecipeUnchecked(RecipeRegistry.java:245) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipe(RecipeRegistry.java:216) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipe(RecipeRegistry.java:183) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipes(RecipeRegistry.java:166) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.<init>(RecipeRegistry.java:92) [RecipeRegistry.class:?] at mezz.jei.util.ModRegistry.createRecipeRegistry(ModRegistry.java:204) [ModRegistry.class:?] at mezz.jei.JeiStarter.start(JeiStarter.java:57) [JeiStarter.class:?] at mezz.jei.ProxyCommonClient.loadComplete(ProxyCommonClient.java:115) [ProxyCommonClient.class:?] at mezz.jei.JustEnoughItems.loadComplete(JustEnoughItems.java:71) [JustEnoughItems.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at net.minecraftforge.fml.common.FMLModContainer.handleModStateEvent(FMLModContainer.java:600) [FMLModContainer.class:?] at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at com.google.common.eventbus.EventSubscriber.handleEvent(EventSubscriber.java:74) [guava-17.0.jar:?] at com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:47) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatch(EventBus.java:322) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.post(EventBus.java:275) [guava-17.0.jar:?] at net.minecraftforge.fml.common.LoadController.sendEventToModContainer(LoadController.java:239) [LoadController.class:?] at net.minecraftforge.fml.common.LoadController.propogateStateMessage(LoadController.java:217) [LoadController.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at com.google.common.eventbus.EventSubscriber.handleEvent(EventSubscriber.java:74) [guava-17.0.jar:?] at com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:47) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatch(EventBus.java:322) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.post(EventBus.java:275) [guava-17.0.jar:?] at net.minecraftforge.fml.common.LoadController.distributeStateMessage(LoadController.java:142) [LoadController.class:?] at net.minecraftforge.fml.common.Loader.initializeMods(Loader.java:803) [Loader.class:?] at net.minecraftforge.fml.client.FMLClientHandler.finishMinecraftLoading(FMLClientHandler.java:324) [FMLClientHandler.class:?] at net.minecraft.client.Minecraft.func_71384_a(Minecraft.java:520) [bcx.class:?] at net.minecraft.client.Minecraft.func_99999_d(Minecraft.java:351) [bcx.class:?] at net.minecraft.client.main.Main.main(SourceFile:124) [Main.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at net.minecraft.launchwrapper.Launch.launch(Launch.java:135) [launchwrapper-1.12.jar:?] at net.minecraft.launchwrapper.Launch.main(Launch.java:28) [launchwrapper-1.12.jar:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at org.multimc.onesix.OneSixLauncher.launchWithMainClass(OneSixLauncher.java:310) [NewLaunch.jar:?] at org.multimc.onesix.OneSixLauncher.launch(OneSixLauncher.java:395) [NewLaunch.jar:?] at org.multimc.EntryPoint.listen(EntryPoint.java:170) [NewLaunch.jar:?] at org.multimc.EntryPoint.main(EntryPoint.java:54) [NewLaunch.jar:?] [15:48:44] [Client thread/ERROR]: Null item in itemStack java.lang.NullPointerException at mezz.jei.util.StackHelper.getSubtypes(StackHelper.java:218) [StackHelper.class:?] at mezz.jei.util.StackHelper.getAllSubtypes(StackHelper.java:292) [StackHelper.class:?] at mezz.jei.util.StackHelper.getAllSubtypes(StackHelper.java:270) [StackHelper.class:?] at mezz.jei.plugins.vanilla.ingredients.ItemStackHelper.expandSubtypes(ItemStackHelper.java:24) [ItemStackHelper.class:?] at mezz.jei.util.Ingredients.setOutput(Ingredients.java:62) [Ingredients.class:?] at mezz.jei.plugins.vanilla.crafting.ShapedOreRecipeWrapper.getIngredients(ShapedOreRecipeWrapper.java:45) [ShapedOreRecipeWrapper.class:?] at mezz.jei.RecipeRegistry.addRecipeUnchecked(RecipeRegistry.java:245) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipe(RecipeRegistry.java:216) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipe(RecipeRegistry.java:183) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.addRecipes(RecipeRegistry.java:166) [RecipeRegistry.class:?] at mezz.jei.RecipeRegistry.<init>(RecipeRegistry.java:92) [RecipeRegistry.class:?] at mezz.jei.util.ModRegistry.createRecipeRegistry(ModRegistry.java:204) [ModRegistry.class:?] at mezz.jei.JeiStarter.start(JeiStarter.java:57) [JeiStarter.class:?] at mezz.jei.ProxyCommonClient.loadComplete(ProxyCommonClient.java:115) [ProxyCommonClient.class:?] at mezz.jei.JustEnoughItems.loadComplete(JustEnoughItems.java:71) [JustEnoughItems.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at net.minecraftforge.fml.common.FMLModContainer.handleModStateEvent(FMLModContainer.java:600) [FMLModContainer.class:?] at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at com.google.common.eventbus.EventSubscriber.handleEvent(EventSubscriber.java:74) [guava-17.0.jar:?] at com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:47) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatch(EventBus.java:322) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.post(EventBus.java:275) [guava-17.0.jar:?] at net.minecraftforge.fml.common.LoadController.sendEventToModContainer(LoadController.java:239) [LoadController.class:?] at net.minecraftforge.fml.common.LoadController.propogateStateMessage(LoadController.java:217) [LoadController.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at com.google.common.eventbus.EventSubscriber.handleEvent(EventSubscriber.java:74) [guava-17.0.jar:?] at com.google.common.eventbus.SynchronizedEventSubscriber.handleEvent(SynchronizedEventSubscriber.java:47) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatch(EventBus.java:322) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.dispatchQueuedEvents(EventBus.java:304) [guava-17.0.jar:?] at com.google.common.eventbus.EventBus.post(EventBus.java:275) [guava-17.0.jar:?] at net.minecraftforge.fml.common.LoadController.distributeStateMessage(LoadController.java:142) [LoadController.class:?] at net.minecraftforge.fml.common.Loader.initializeMods(Loader.java:803) [Loader.class:?] at net.minecraftforge.fml.client.FMLClientHandler.finishMinecraftLoading(FMLClientHandler.java:324) [FMLClientHandler.class:?] at net.minecraft.client.Minecraft.func_71384_a(Minecraft.java:520) [bcx.class:?] at net.minecraft.client.Minecraft.func_99999_d(Minecraft.java:351) [bcx.class:?] at net.minecraft.client.main.Main.main(SourceFile:124) [Main.class:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at net.minecraft.launchwrapper.Launch.launch(Launch.java:135) [launchwrapper-1.12.jar:?] at net.minecraft.launchwrapper.Launch.main(Launch.java:28) [launchwrapper-1.12.jar:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_101] at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_101] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_101] at org.multimc.onesix.OneSixLauncher.launchWithMainClass(OneSixLauncher.java:310) [NewLaunch.jar:?] at org.multimc.onesix.OneSixLauncher.launch(OneSixLauncher.java:395) [NewLaunch.jar:?] at org.multimc.EntryPoint.listen(EntryPoint.java:170) [NewLaunch.jar:?] at org.multimc.EntryPoint.main(EntryPoint.java:54) [NewLaunch.jar:?] [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@5f0f17e0 [15:48:46] [Client thread/ERROR]: Unknown object found: com.brandon3055.draconicevolution.items.ItemPersistent@73ba299 [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@19d33d5c [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@5f0f17e0 [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@19d33d5c [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@48f2228e [15:48:46] [Client thread/ERROR]: Unknown object found: Block{minecraft:dragon_egg} [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@19d33d5c [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: com.brandon3055.draconicevolution.items.tools.DraconicShovel@2e9a461e [15:48:46] [Client thread/ERROR]: Unknown object found: com.brandon3055.draconicevolution.items.tools.DraconicSword@663f8757 [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@7de2bdad [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@6fdc751a [15:48:46] [Client thread/ERROR]: Unknown object found: net.minecraft.item.Item@19d33d5c [15:48:47] [Client thread/INFO]: Built recipe registry in 3183 ms [15:48:47] [Client thread/INFO]: Building runtime... [15:48:47] [Client thread/INFO]: Built runtime in 45 ms [15:48:47] [Client thread/INFO]: Building item filter... This is what i get in log before Adding itemStack ingredients. -

mezz commented 7 years ago

@iTraumatik It is not Optifine for you?

iTraumatik commented 7 years ago

@mezz Correct. I just updated my last post plz look. Thanks for checking this out

mezz commented 7 years ago

Submitted a new issue to Optifine here: https://github.com/sp614x/optifine/issues/304

mezz commented 7 years ago

@iTraumatik you have a separate issue. Please try removing mods until you no longer see the issue. If you find out more, please open a new issue instead of replying here.

mezz commented 7 years ago

Looks like it has to do with the splash screen loading bars. If I disable the splash screen (config/splash.properties), everything loads quickly.

mezz commented 7 years ago

After talking with Forge, this is an issue involving vsync, the splash screen, and checking for keyboard inputs. It can't be fixed on Forge's side, but I am adding a workaround to make the item loading splash screen work much much faster.

mezz commented 7 years ago

Fixed in JEI 3.13.0.339