[1.4.0.3] - Severe performance issue (some metrics and sampler data included)

[cosmicdan]

Howdy,

Love the customization this mod provides. Sadly there is a huge performance issue at the late stage of loading. I don't know if this is a specific incompatibility with JEI but I doubt it.

Behold:

The end of JEI loading took NINE seconds (as opposed to like <100ms without it) and the... whatever happens at the end took ~6 seconds.

Note that this happens with the default sample screen. On the others, it hangs for a VERY long time - I didn't even bother waiting for it to finish (>30 seconds).

I've tried to do VisualVM profiling, maybe it makes more sense to you than me.

Screenshot of what appears to be the first big pause (JEI part):

And one for the second big pause, I think. Hard to tell:

As I said it makes little sense to me, but maybe it will give you a hint. If I had to guess, I'd say it's a combination of reflection overhead and "responding to events" that aren't strictly necessary.

Since I noticed the non-default loading screens are far worse, I'll go and see if I can create a minimal/blank loading screen and see if it's any different. I'll try that Resource Loader mod too.

[cosmicdan]

Note - disabling JEI Integration dropped ~1.5 seconds off the first one, but the results are generally the same:

[cosmicdan]

Oh, here's the two snapshots too if you want to compare them yourself.

I'll check out the Resource Loader and/or blank config now.

snapshots.zip

[AlexIIL]

If it's in Keyboard.isKeyDown then it's likely due to a problem with how CLS moves control of opengl from the main thread to it's own rendering thread. However I'm a bit confused as theoretically CLS should do the same things that forge does.

[cosmicdan]

That makes sense. So basically it's switching context (or whatever the Java native equivalent term is) back and fourth, over and over, since JEI needs it to calculate alignment/size of tooltips and it needs e.g. FontRenderer to do that?

Hmm. If you can think of a quick code hack I could do to test anything, let me know - more than happy to set up a dev environment. No rush though :)

[AlexIIL]

I'm not likely to tacke this anytime soon as I'm focusing on buildcraft.

[AlexIIL]

This is might be related to CraftTweaker/CraftTweaker#377 as the method in question is in crafttweaker to see if they should add additional item tooltips.

[cosmicdan]

This is might be related to CraftTweaker/CraftTweaker#377 as the method in question is in crafttweaker to see if they should add additional item tooltips.

Thanks for looking more into it. Removed CraftTweaker (and all dependents), and JEI Integration one, and while the time result is essentially the same, a profiling comparison now shows that the time increases are more spread out. Tinker's Construct, is taking the brunt of it now, and sure enough it ends at the native LWJGL call to isKeyDown(). This time, nothing to do with tooltips they're specifically checking for Shift and Ctrl too, I don't see anything about tooltips in particular (though methods are obfuscated, obviously). The pauses still occur at the same places as they originally did with minimal time reduction.

I don't know much about Java's JNI/Native interfacing, but this looks like classic thread contention behaviour to me.

[cosmicdan]

Also note that, during these pauses, the Minecraft window is "Not Responding". That kind of thing happens in larger mod packs a lot, I'm sure you already know. So this is probably also a "bug" (limitation) in Forge itself but just being amplified by CLS's extra handles for all the fancyness it provides.

So.... I guess technically, this isn't really a "bug" with CLS. Could be a bug with Forge, Minecraft or LWJGL itself for all I know lol.

[AlexIIL]

a profiling comparison now shows that the time increases are more spread out....

Ah ok, that's interesting.

So this is probably also a "bug" (limitation) in Forge itself but just being amplified by CLS's extra handles for all the fancyness it provides.

It seems unlikely that it's due to CLS being expensive (it's limited to 100fps, and it's a lot cheaper to render than a vanilla minecraft world). I'm not sure what the actual cause is though - does it happen with CLS disabled?

[cosmicdan]

It seems unlikely that it's due to CLS being expensive (it's limited to 100fps, and it's a lot cheaper to render than a vanilla minecraft world).

Yeah, I didn't think so - but I mean, I don't know. I'm going to fiddle around with it and see if I can find anything interesting.

does it happen with CLS disabled?

Do you mean with the mod completely removed? No, of course not :)

I don't know of any other way to "disable" the mod. I've tried setting both smooth_init and use_custom (is that one supposed to disable it? Because it doesn't) to false but I don't notice any difference.

[cosmicdan]

OK, please don't spend any more time on this until at least one other person can confirm the issue. Something weird is going on - the last test I did took over a minute for JEI, and I got sick of waiting for the second pause to finish after ~3 minutes. Hopefully I haven't just wasted your time!