Less aggressive System.nanoTime() (#2269)

* Less aggressive System.nanoTime()

* Address reviews

3 files changed, 101 insertions, 42 deletions

diff --git a/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java b/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java
index 4aa2464853..6a1d303a2f 100644
--- a/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java
+++ b/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java
@@ -57,6 +57,7 @@ public class BaseMetaPipeEntity extends CommonMetaTileEntity
     public byte mConnections = IConnectable.NO_CONNECTION;
     protected MetaPipeEntity mMetaTileEntity;
     private final int[] mTimeStatistics = new int[GregTech_API.TICKS_FOR_LAG_AVERAGING];
+    private boolean hasTimeStatisticsStarted;
     private boolean mWorkUpdate = false, mWorks = true;
     private byte mColor = 0, oColor = 0, oStrongRedstone = 0, oRedstoneData = 63, oTextureData = 0, oUpdateData = 0,
         mLagWarningCount = 0;
@@ -165,7 +166,12 @@ public class BaseMetaPipeEntity extends CommonMetaTileEntity
             mMetaTileEntity.setBaseMetaTileEntity(this);
         }
 
-        long tTime = System.nanoTime();
+        long tTime;
+        if (hasTimeStatisticsStarted) {
+            tTime = System.nanoTime();
+        } else {
+            tTime = 0;
+        }
         try {
             if (hasValidMetaTileEntity()) {
                 if (mTickTimer++ == 0) {
@@ -258,10 +264,10 @@ public class BaseMetaPipeEntity extends CommonMetaTileEntity
             e.printStackTrace(GT_Log.err);
         }
 
-        if (isServerSide() && hasValidMetaTileEntity()) {
+        if (isServerSide() && hasTimeStatisticsStarted && hasValidMetaTileEntity()) {
             tTime = System.nanoTime() - tTime;
-            if (mTimeStatistics.length > 0) mTimeStatistics[mTimeStatisticsIndex = (mTimeStatisticsIndex + 1)
-                % mTimeStatistics.length] = (int) tTime;
+            mTimeStatisticsIndex = (mTimeStatisticsIndex + 1) % mTimeStatistics.length;
+            mTimeStatistics[mTimeStatisticsIndex] = (int) tTime;
             if (tTime > 0 && tTime > (GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING * 1000000L)
                 && mTickTimer > 1000
                 && getMetaTileEntity().doTickProfilingMessageDuringThisTick()
@@ -397,22 +403,33 @@ public class BaseMetaPipeEntity extends CommonMetaTileEntity
                         : " "));
         }
         if (aLogLevel > 1) {
-            if (mTimeStatistics.length > 0) {
+            if (hasTimeStatisticsStarted) {
                 double tAverageTime = 0;
                 double tWorstTime = 0;
+                int amountOfZero = 0;
                 for (int tTime : mTimeStatistics) {
                     tAverageTime += tTime;
                     if (tTime > tWorstTime) {
                         tWorstTime = tTime;
                     }
+                    if (tTime == 0) {
+                        amountOfZero += 1;
+                    }
                 }
-                tList.add(
-                    "Average CPU-load of ~" + (tAverageTime / mTimeStatistics.length)
-                        + "ns since "
-                        + mTimeStatistics.length
-                        + " ticks with worst time of "
-                        + tWorstTime
-                        + "ns.");
+                // tick time zero means it has not been updated yet
+                int samples = mTimeStatistics.length - amountOfZero;
+                if (samples > 0) {
+                    tList.add(
+                        "Average CPU-load of ~" + (tAverageTime / samples)
+                            + "ns since "
+                            + samples
+                            + " ticks with worst time of "
+                            + tWorstTime
+                            + "ns.");
+                }
+            } else {
+                startTimeStatistics();
+                tList.add("Just started tick time statistics.");
             }
             if (mLagWarningCount > 0) {
                 tList.add(
@@ -1372,4 +1389,14 @@ public class BaseMetaPipeEntity extends CommonMetaTileEntity
     public void onEntityCollidedWithBlock(World aWorld, int aX, int aY, int aZ, Entity collider) {
         mMetaTileEntity.onEntityCollidedWithBlock(aWorld, aX, aY, aZ, collider);
     }
+
+    @Override
+    public int[] getTimeStatistics() {
+        return mTimeStatistics;
+    }
+
+    @Override
+    public void startTimeStatistics() {
+        hasTimeStatisticsStarted = true;
+    }
 }
diff --git a/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java b/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java
index 1c403dcf7f..af1fbace15 100644
--- a/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java
+++ b/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java
@@ -95,6 +95,7 @@ public class BaseMetaTileEntity extends CommonMetaTileEntity
     private final boolean[] mActiveEUInputs = new boolean[] { false, false, false, false, false, false };
     private final boolean[] mActiveEUOutputs = new boolean[] { false, false, false, false, false, false };
     private final int[] mTimeStatistics = new int[GregTech_API.TICKS_FOR_LAG_AVERAGING];
+    private boolean hasTimeStatisticsStarted;
     public long mLastSoundTick = 0;
     public boolean mWasShutdown = false;
     protected MetaTileEntity mMetaTileEntity;
@@ -283,7 +284,12 @@ public class BaseMetaTileEntity extends CommonMetaTileEntity
         }
 
         mRunningThroughTick = true;
-        long tTime = System.nanoTime();
+        long tTime;
+        if (hasTimeStatisticsStarted) {
+            tTime = System.nanoTime();
+        } else {
+            tTime = 0;
+        }
         final boolean aSideServer = isServerSide();
         final boolean aSideClient = isClientSide();
 
@@ -604,10 +610,10 @@ public class BaseMetaTileEntity extends CommonMetaTileEntity
             }
         }
 
-        if (aSideServer && hasValidMetaTileEntity()) {
+        if (aSideServer && hasTimeStatisticsStarted && hasValidMetaTileEntity()) {
             tTime = System.nanoTime() - tTime;
-            if (mTimeStatistics.length > 0) mTimeStatistics[mTimeStatisticsIndex = (mTimeStatisticsIndex + 1)
-                % mTimeStatistics.length] = (int) tTime;
+            mTimeStatisticsIndex = (mTimeStatisticsIndex + 1) % mTimeStatistics.length;
+            mTimeStatistics[mTimeStatisticsIndex] = (int) tTime;
             if (tTime > 0 && tTime > (GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING * 1_000_000L)
                 && mTickTimer > 1000
                 && getMetaTileEntity().doTickProfilingMessageDuringThisTick()
@@ -801,33 +807,44 @@ public class BaseMetaTileEntity extends CommonMetaTileEntity
                         ? EnumChatFormatting.RED + " MetaTileEntity == null!" + EnumChatFormatting.RESET
                         : " "));
         }
-        if (aLogLevel > 1) {
-            if (mTimeStatistics.length > 0) {
+        if (aLogLevel > 1 && mMetaTileEntity != null) {
+            if (hasTimeStatisticsStarted) {
                 double tAverageTime = 0;
                 double tWorstTime = 0;
+                int amountOfZero = 0;
                 for (int tTime : mTimeStatistics) {
                     tAverageTime += tTime;
                     if (tTime > tWorstTime) {
                         tWorstTime = tTime;
                     }
+                    if (tTime == 0) {
+                        amountOfZero += 1;
+                    }
                     // Uncomment this line to print out tick-by-tick times.
                     // tList.add("tTime " + tTime);
                 }
-                tList.add(
-                    "Average CPU load of ~" + GT_Utility.formatNumbers(tAverageTime / mTimeStatistics.length)
-                        + "ns over "
-                        + GT_Utility.formatNumbers(mTimeStatistics.length)
-                        + " ticks with worst time of "
-                        + GT_Utility.formatNumbers(tWorstTime)
-                        + "ns.");
-                tList.add(
-                    "Recorded " + GT_Utility.formatNumbers(mMetaTileEntity.mSoundRequests)
-                        + " sound requests in "
-                        + GT_Utility.formatNumbers(mTickTimer - mLastCheckTick)
-                        + " ticks.");
-                mLastCheckTick = mTickTimer;
-                mMetaTileEntity.mSoundRequests = 0;
+                // tick time zero means it has not been updated yet
+                int samples = mTimeStatistics.length - amountOfZero;
+                if (samples > 0) {
+                    tList.add(
+                        "Average CPU load of ~" + GT_Utility.formatNumbers(tAverageTime / samples)
+                            + "ns over "
+                            + GT_Utility.formatNumbers(samples)
+                            + " ticks with worst time of "
+                            + GT_Utility.formatNumbers(tWorstTime)
+                            + "ns.");
+                }
+            } else {
+                startTimeStatistics();
+                tList.add("Just started tick time statistics.");
             }
+            tList.add(
+                "Recorded " + GT_Utility.formatNumbers(mMetaTileEntity.mSoundRequests)
+                    + " sound requests in "
+                    + GT_Utility.formatNumbers(mTickTimer - mLastCheckTick)
+                    + " ticks.");
+            mLastCheckTick = mTickTimer;
+            mMetaTileEntity.mSoundRequests = 0;
             if (mLagWarningCount > 0) {
                 tList.add(
                     "Caused " + (mLagWarningCount >= 10 ? "more than 10" : mLagWarningCount)
@@ -2449,6 +2466,11 @@ public class BaseMetaTileEntity extends CommonMetaTileEntity
     }
 
     @Override
+    public void startTimeStatistics() {
+        hasTimeStatisticsStarted = true;
+    }
+
+    @Override
     public String getCustomName() {
         return getMetaTileEntity() instanceof ICustomNameObject customNameObject ? customNameObject.getCustomName()
             : null;
diff --git a/src/main/java/gregtech/api/metatileentity/implementations/GT_MetaTileEntity_MultiBlockBase.java b/src/main/java/gregtech/api/metatileentity/implementations/GT_MetaTileEntity_MultiBlockBase.java
index 9d86608bf4..ff2ecfa83f 100644
--- a/src/main/java/gregtech/api/metatileentity/implementations/GT_MetaTileEntity_MultiBlockBase.java
+++ b/src/main/java/gregtech/api/metatileentity/implementations/GT_MetaTileEntity_MultiBlockBase.java
@@ -68,6 +68,7 @@ import gregtech.api.objects.GT_ItemStack;
 import gregtech.api.recipe.check.CheckRecipeResult;
 import gregtech.api.recipe.check.CheckRecipeResultRegistry;
 import gregtech.api.recipe.check.SingleRecipeCheck;
+import gregtech.api.util.GT_ClientPreference;
 import gregtech.api.util.GT_ExoticEnergyInputHelper;
 import gregtech.api.util.GT_Log;
 import gregtech.api.util.GT_ParallelHelper;
@@ -1767,7 +1768,7 @@ public abstract class GT_MetaTileEntity_MultiBlockBase extends MetaTileEntity
         currentTip.add(
             GT_Waila.getMachineProgressString(isActive, tag.getInteger("maxProgress"), tag.getInteger("progress")));
         // Show ns on the tooltip
-        if (GT_Mod.gregtechproxy.wailaAverageNS) {
+        if (GT_Mod.gregtechproxy.wailaAverageNS && tag.hasKey("averageNS")) {
             int tAverageTime = tag.getInteger("averageNS");
             currentTip.add("Average CPU load of ~" + formatNumbers(tAverageTime) + " ns");
         }
@@ -1795,16 +1796,25 @@ public abstract class GT_MetaTileEntity_MultiBlockBase extends MetaTileEntity
             }
         }
 
-        int tAverageTime = 0;
-        for (int tTime : this.getBaseMetaTileEntity()
-            .getTimeStatistics()) {
-            tAverageTime += tTime;
-        }
+        final GT_ClientPreference preference = GT_Mod.gregtechproxy.getClientPreference(player.getUniqueID());
+        if (preference != null && preference.isWailaAverageNSEnabled()) {
+            getBaseMetaTileEntity().startTimeStatistics();
+            int tAverageTime = 0;
+            int amountOfZero = 0;
+            for (int tTime : this.getBaseMetaTileEntity()
+                .getTimeStatistics()) {
+                tAverageTime += tTime;
+                if (tTime == 0) {
+                    amountOfZero += 1;
+                }
+            }
 
-        tag.setInteger(
-            "averageNS",
-            tAverageTime / this.getBaseMetaTileEntity()
-                .getTimeStatistics().length);
+            // tick time zero means it has not been updated yet
+            int samples = getBaseMetaTileEntity().getTimeStatistics().length - amountOfZero;
+            if (samples > 0) {
+                tag.setInteger("averageNS", tAverageTime / samples);
+            }
+        }
     }
 
     @Override