Minecraft服务端卡顿问题排查分析

Colorful_Ghost

2019-03-14

Minecraft Arthas

162

排查工具：arthas

今早无意查看我服Sponge服务端刷出大量的：

Can't keep up! Did the system time change, or is the server overloaded? Running 5400ms behind, skipping 108 tick(s)

也就代表某个线程跑满 tick主频不够用了。

但是得排查出具体原因，首先我们先使用htop看下CPU占用率，和主线程PID

发现占用挺高.....现在用查到的PID进入arthas里面

输入：dashboard

!https://s3-us-west-2.amazonaws.com/secure.notion-static.com/10e53952-7427-4118-a1b4-2100f11e5687/Untitled.png

发现服务端主线程长时间占用率还挺高。

然后尝试几次 thread -n 2 查询占用最高的2个线程

[arthas@307]$ thread -n 2
"Server thread" Id=20 cpuUsage=97% RUNNABLE
    at sun.reflect.Reflection.getCallerClass(Native Method)
    at java.lang.Class.getClassLoader(Class.java:683)
    at gregtech.common.pipelike.cable.tile.CableEnergyContainer.dispatchEnergyToNode(CableEnergyContainer.java)
    at gregtech.common.pipelike.cable.tile.CableEnergyContainer.acceptEnergyFromNetwork(CableEnergyContainer.java:46)
    at gregtech.api.capability.impl.EnergyContainerHandler.update(EnergyContainerHandler.java:150)
    at gregtech.api.metatileentity.MetaTileEntity.update(MetaTileEntity.java:557)
    at gregtech.api.metatileentity.MetaTileEntityHolder.func_73660_a(MetaTileEntityHolder.java:155)
    at org.spongepowered.common.event.tracking.TrackingUtil.tickTileEntity(TrackingUtil.java:237)
    at net.minecraft.world.WorldServer.updateTileEntity(WorldServer.java:4728)
    at net.minecraft.world.WorldServer.redirect$onUpdateTileEntities$zlk000(WorldServer.java:4712)
    at net.minecraft.world.World.func_72939_s(World.java:1838)
    at net.minecraft.world.WorldServer.func_72939_s(WorldServer.java:3930)
    at net.minecraft.server.MinecraftServer.func_71190_q(MinecraftServer.java:767)
    at net.minecraft.server.dedicated.DedicatedServer.func_71190_q(DedicatedServer.java:397)
    at net.minecraft.server.MinecraftServer.func_71217_p(MinecraftServer.java:668)
    at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:526)
    at java.lang.Thread.run(Thread.java:748)

发现格雷科技里的线缆这个功能 dispatchEnergyToNode方法 CPU使用率异常高

然后去Github上看了GTCE的这一块代码

https://github.com/GregTechCE/GregTech/blob/master/src/main/java/gregtech/api/capability/impl/EnergyContainerHandler.java:150

https://github.com/GregTechCE/GregTech/blob/master/src/main/java/gregtech/common/pipelike/cable/tile/CableEnergyContainer.java

发现metaTileEntity实体触发更新导致以上流程里面几层循环调用，消耗大.....作者这么写心宽啊

好了我们要查一下metaTileEntity下面具体到游戏里的哪一个方块，从物理上解决....

从上面的代码可以看出来

at gregtech.api.metatileentity.MetaTileEntity.update(MetaTileEntity.java:557)

在做更新操作看看这个更新代码是在哪里调用的

我们使用arthas 的 watch 看看这个实体里面有什么

watch gregtech.api.metatileentity.MetaTileEntity shouldUpdate "params" -x 3 -b

params是调方法的参数 -b是标识调用前的内容 -x 3 是对象深度3层，这个对象在第三层貌似就获取到了坐标数据

我就取了一个查询耗时最长的一个实体到游戏里看看

游戏里/tppos 411 3 -478

最后查询到罪魁祸首应该是这些方块....

结果：阵列涡轮系统里的动力仓能源一直在更新导致卡服（呕

大概思路就是这样吧，Minecraft和区块世界相关都在主线程上，所以开MC服务器还是用尽量高主频U，另外阿里的arthas排查JVM问题超级好用！