From 032a77dac00ca4ec98a7af3f16d7f99191727d60 Mon Sep 17 00:00:00 2001 From: Richard Hendricks Date: Wed, 30 May 2018 01:09:15 -0500 Subject: Branch to add in better debug output from GT cpu load. ns instead of ms. --- .../api/metatileentity/BaseMetaPipeEntity.java | 18 ++++++++++++------ .../api/metatileentity/BaseMetaTileEntity.java | 18 ++++++++++++------ 2 files changed, 24 insertions(+), 12 deletions(-) (limited to 'src') diff --git a/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java b/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java index a761afd5cb..0d06c4ec03 100644 --- a/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java +++ b/src/main/java/gregtech/api/metatileentity/BaseMetaPipeEntity.java @@ -183,7 +183,7 @@ public class BaseMetaPipeEntity extends BaseTileEntity implements IGregTechTileE mMetaTileEntity.setBaseMetaTileEntity(this); } - long tTime = System.currentTimeMillis(); + long tTime = System.nanoTime(); int tCode = 0; try { for (tCode = 0; hasValidMetaTileEntity() && tCode >= 0; ) { @@ -298,11 +298,11 @@ public class BaseMetaPipeEntity extends BaseTileEntity implements IGregTechTileE } if (isServerSide() && hasValidMetaTileEntity()) { - tTime = System.currentTimeMillis() - tTime; + tTime = System.nanoTime() - tTime; if (mTimeStatistics.length > 0) mTimeStatistics[mTimeStatisticsIndex = (mTimeStatisticsIndex + 1) % mTimeStatistics.length] = (int) tTime; - if (tTime > 0 && tTime > GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING && mTickTimer > 1000 && getMetaTileEntity().doTickProfilingMessageDuringThisTick() && mLagWarningCount++ < 10) - FMLLog.warning("WARNING: Possible Lag Source at [%s,%s,%s] in Dimension %s with %s ms caused by an instance of %s", xCoord, yCoord, zCoord, worldObj.provider.dimensionId, tTime, getMetaTileEntity().getClass()); + if (tTime > 0 && tTime > (GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING*1000000) && mTickTimer > 1000 && getMetaTileEntity().doTickProfilingMessageDuringThisTick() && mLagWarningCount++ < 10) + FMLLog.warning("WARNING: Possible Lag Source at [%s,%s,%s] in Dimension %s with %s ns caused by an instance of %s", xCoord, yCoord, zCoord, worldObj.provider.dimensionId, tTime, getMetaTileEntity().getClass()); } mWorkUpdate = mInventoryChanged = false; @@ -395,8 +395,14 @@ public class BaseMetaPipeEntity extends BaseTileEntity implements IGregTechTileE if (aLogLevel > 1) { if (mTimeStatistics.length > 0) { double tAverageTime = 0; - for (int tTime : mTimeStatistics) tAverageTime += tTime; - tList.add("Average CPU-load of ~" + (tAverageTime / mTimeStatistics.length) + "ms since " + mTimeStatistics.length + " ticks."); + double tWorstTime = 0; + for (int tTime : mTimeStatistics) { + tAverageTime += tTime; + if (tTime > tWorstTime) { + tWorstTime = tTime; + } + } + tList.add("Average CPU-load of ~" + (tAverageTime / mTimeStatistics.length) + "ns since " + mTimeStatistics.length + " ticks with worst time of " + tWorstTime + "ns."); } if (mLagWarningCount > 0) { tList.add("Caused " + (mLagWarningCount >= 10 ? "more than 10" : mLagWarningCount) + " Lag Spike Warnings (anything taking longer than " + GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING + "ms) on the Server."); diff --git a/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java b/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java index d44ada526f..609a35bfae 100644 --- a/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java +++ b/src/main/java/gregtech/api/metatileentity/BaseMetaTileEntity.java @@ -277,7 +277,7 @@ public class BaseMetaTileEntity extends BaseTileEntity implements IGregTechTileE } mRunningThroughTick = true; - long tTime = System.currentTimeMillis(); + long tTime = System.nanoTime(); int tCode = 0; boolean aSideServer = isServerSide(); boolean aSideClient = isClientSide(); @@ -573,11 +573,11 @@ public class BaseMetaTileEntity extends BaseTileEntity implements IGregTechTileE } if (aSideServer && hasValidMetaTileEntity()) { - tTime = System.currentTimeMillis() - tTime; + tTime = System.nanoTime() - tTime; if (mTimeStatistics.length > 0) mTimeStatistics[mTimeStatisticsIndex = (mTimeStatisticsIndex + 1) % mTimeStatistics.length] = (int) tTime; - if (tTime > 0 && tTime > GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING && mTickTimer > 1000 && getMetaTileEntity().doTickProfilingMessageDuringThisTick() && mLagWarningCount++ < 10) - System.out.println("WARNING: Possible Lag Source at [" + xCoord + ", " + yCoord + ", " + zCoord + "] in Dimension " + worldObj.provider.dimensionId + " with " + tTime + "ms caused by an instance of " + getMetaTileEntity().getClass()); + if (tTime > 0 && tTime > (GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING*1000000) && mTickTimer > 1000 && getMetaTileEntity().doTickProfilingMessageDuringThisTick() && mLagWarningCount++ < 10) + System.out.println("WARNING: Possible Lag Source at [" + xCoord + ", " + yCoord + ", " + zCoord + "] in Dimension " + worldObj.provider.dimensionId + " with " + tTime + "ns caused by an instance of " + getMetaTileEntity().getClass()); } mWorkUpdate = mInventoryChanged = mRunningThroughTick = false; @@ -706,8 +706,14 @@ public class BaseMetaTileEntity extends BaseTileEntity implements IGregTechTileE if (aLogLevel > 1) { if (mTimeStatistics.length > 0) { double tAverageTime = 0; - for (int tTime : mTimeStatistics) tAverageTime += tTime; - tList.add("Average CPU-load of ~" + (tAverageTime / mTimeStatistics.length) + "ms since " + mTimeStatistics.length + " ticks."); + double tWorstTime = 0; + for (int tTime : mTimeStatistics) { + tAverageTime += tTime; + if (tTime > tWorstTime) { + tWorstTime = tTime; + } + } + tList.add("Average CPU-load of ~" + (tAverageTime / mTimeStatistics.length) + "ns since " + mTimeStatistics.length + " ticks with worst time of " + tWorstTime + "ns."); } if (mLagWarningCount > 0) { tList.add("Caused " + (mLagWarningCount >= 10 ? "more than 10" : mLagWarningCount) + " Lag Spike Warnings (anything taking longer than " + GregTech_API.MILLISECOND_THRESHOLD_UNTIL_LAG_WARNING + "ms) on the Server."); -- cgit