So I've wanted to try and get some details on how long some of my code takes to execute, and thought I'd hook right in to the Shift-F3 display and was able to dig up these calls (this being a location-agnostic call to the server's profiler) from where it is used elsewhere in the code:

 

MinecraftServer.getServer().theProfiler.startSection("_NAME_");
MinecraftServer.getServer().theProfiler.endSection();

 

Though I've never been able to find any of the sections I name in the F3 overlay (and frequently see a lot of time spent in

root.tick.gameMode.checkLight.checkPosition < toCheckCount

, on the order of 17% of the entire game loop time, and which I have no idea what that even is).

 

My code that I'm trying to profile is inside a tick handler, so it should be in root.tick somewhere.

 

Anyone have any experience with this?

Are you using ServerTickEvent? Because if so... good luck.

The profiler is cleared up right after the START phase (it fires before the vanilla code) and it's main category is ended right before the END phase.

 

Ahhh, I see.  I'm running my code on TickPhase.End, but if the main profiler section was already ended then its too late.

Bummer.

 

Any idea on "checkPosition < toCheckCount"?  When I get a lot of lag in dev, that's the section that's using the most CPU (over a third of the total is root.tick, two thirds of that is root.tick.gameMode, two thirds of that is root.tick.gameMode.checkLight or about 17% of the grand total).

Make sure you are running the latest forge. There was a bug with chunk packets which caused client-side chunk loading to be highly inefficient.

 

Ah, that could be.  I've mostly not worried about it, as I can't trace it back to my code, thought it has been annoying at times.

From memory the "checkPosition < toCheckCount" is related to lighting calculations.  I once did troubleshooting on a mod which had extreme lag during startup and world generation, it was caused because he had a lot of objects in the sky and rather poor initial guess for the skylight grid.  The way lighting calculations are done causes a recursive cascade of updates to the lighting values of blocks and their neighbours, which is extremely slow.

 

-TGG

That was my guess, too.