1. The forums will be archived and moved to a read only mode in about 2 weeks (mid march).

Any cleanup?

Discussion in 'Development' started by kniffo80, Apr 1, 2017.

  1. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    Hi guys,

    the PureEntities plugin at the moment suffers from time to time from a huge server lag. And I'm asking myself if there is a known cleanup of NBT data in the Server implementation.

    Here's the story:
    1. the Server gets started with plugin enabled - everything is fine and no lag
    2. after some time - mostly after a few hours the server gets laggy until it's not playable anymore (this is mostly in the evening)
    3. after letting it run for a few hours (mostly until the next morning) the lag is completely gone
    4. when lag is there and the server gets stopped and started again WITHOUT the plugin enabled - the lag is still there

    My assumption: it's about the NBT implementation. But I ask myself why - after several hours - the lag is gone. So the question is: is there a cleanup or gc or something implemented that runs every x ticks/seconds/minutes/hours. Maybe I can take a look there to check whats causing the bad lag ...

    Ah - this is not an April fool :p
     
  2. EdwardHamHam

    EdwardHamHam Skeleton

    Messages:
    962
    GitHub:
    edwardhamham
    A cleanup of what? NBT tags are simply arguments for certain commands (like /summon for instance) and AFAIK they aren't even implemented in PocketMine yet.
    NBT tags are also not really automated, at least not by default.

    If you need help with NBT tags, the Minecraft wiki (and Google) are the best places to go. As for making certain actions automated, TimeCommander by @LDX would probably be your best bet.
     
  3. Muqsit

    Muqsit Chicken

    Messages:
    1,548
    GitHub:
    muqsit
    It's not your code. So why bother about it on forums than on the GitHub repository?
    PocketMine doesn't "lag" as long as you do not abuse it. I'm pretty sure a server can easily handle 100+ entities. If "entities" cause lag, then so do players, as they are an entity too.
     
    jasonwynn10 and EdwardHamHam like this.
  4. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    I don't need any help with NBT. And I can read wiki - for sure. NBT tags are used for commands? Ah yeah. Just read a little about NBT. NBT is used for storing world data - including Entity Data. So after some time, entities despawn and chunks get unloaded. And where are they stored? In a file in NBT format. When a player re-enters a world - the data of the player is re-created through reading the NBT data. So it's not only used for commands.

    It's not my code? A lot of it is - at least the plugin code. And this is more or less a support forum. And just tfor your information - the plugin can be started without writing own NBT data - when this is not done - the server also starts to lag. So there HAS TO BE a cleanup of SOMETHING - because the lag is gone (maybe by using ghost hands) after a few hours - without doing anything.

    Anyway - I will investigate on this on my own.
     
  5. EdwardHamHam

    EdwardHamHam Skeleton

    Messages:
    962
    GitHub:
    edwardhamham
    I already know everything you said in the first paragraph, it sounds like you think I'm dumb, which I'm not. How powerful is the CPU in the machine that you're running the server on? That may also very well be your problem.

    Try listening to @Muqsit
     
  6. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    So you knew everything i said in the first paragraph? Why did you write:
    Which is not true at the end. I'm not telling you are dump, just that this is not the whole truth.

    2 Cores, 2GB RAM, SSD. Anyway - will not bother anyone here again with this (listening to Muqsit).
     
  7. Muqsit

    Muqsit Chicken

    Messages:
    1,548
    GitHub:
    muqsit
    It is more of things being executed in Entity:: onUpdate($tick) than an NBT issue. Send a timings test, that'll help a lot.
     
    EdwardHamHam likes this.
  8. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    I know - BUT - the plugin has a command to remove all living entities (without players) from all levels of the world (using close function). Even when this command is executed - the server doesn't stop to lag. And again: when the server is lagging, I can stop the server, disable the plugin and the server still continues to lag. After a few hours the lag is gone when no player was at the server for a several amount time.

    So in the first line it has nothing to do with entity ticking. I think it's more or less corrupted chunk data which is loaded when the player logs in.

    EDIT: and yes, I am aware that somehow the plugin is responsible for the lags - but i need to find out WHAT is causing the lag - so my first question is still valid: is there a chunk cleanup / unloading mechanism in the server I can take a look at ;)
     
  9. Thunder33345

    Thunder33345 Moderator Staff Member

    Messages:
    2,137
    GitHub:
    Thunder33345
    maybe timings will help you if you only run that plugin on the server with timings
     
    Jack Noordhuis likes this.
  10. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    Yes - only the plugin and the server. So yes, I'll try with timings.
     
  11. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    I made a short timings session, yesterday in the evening and today in the morning:

    Evening (some lag):
    Code:
    Minecraft
        Full Server Tick Time: 1437797785 Count: 716 Avg: 2008097 Violations: 3
        ** Full Server Tick Time: 1436579466 Count: 716 Avg: 2006396 Violations: 3
        Memory Manager Time: 1859903 Count: 717 Avg: 2594 Violations: 0
        Player Network Send Time: 95692396 Count: 595 Avg: 160828 Violations: 0
        Player Network Receive Time: 22515059 Count: 198 Avg: 113712 Violations: 0
        Player Order Chunks Time: 888348 Count: 11 Avg: 80759 Violations: 0
        Player Send Chunks Time: 89620113 Count: 4 Avg: 22405028 Violations: 1
        Connection Handler Time: 50035954 Count: 717 Avg: 69785 Violations: 0
        Scheduler Time: 12459755 Count: 717 Avg: 17378 Violations: 0
        Server Command Time: 6326675 Count: 716 Avg: 8836 Violations: 0
        ** entityMove Time: 66358566 Count: 887 Avg: 74812 Violations: 0
        ** tickEntity Time: 364704132 Count: 717 Avg: 508653 Violations: 0
        ** tickTileEntity Time: 1680851 Count: 717 Avg: 2344 Violations: 0
        ** entityBaseTick Time: 73785782 Count: 1544 Avg: 47789 Violations: 0
        ** livingEntityBaseTick Time: 30992746 Count: 428 Avg: 72413 Violations: 0
        ** Scheduler - Sync Tasks Time: 2886057 Count: 5 Avg: 577211 Violations: 0
        ** Scheduler - Async Tasks Time: 1598597 Count: 717 Avg: 2230 Violations: 0
        Plugin: PureEntitiesX v0.2.1_dev Event: revivalpmmp\pureentities\event\EventListener::dataPacketReceiveEvent(DataPacketReceiveEvent) Time: 2167463 Count: 412 Avg: 5261 Violations: 0
        Plugin: PureEntitiesX v0.2.1_dev Event: revivalpmmp\pureentities\event\EventListener::playerQuit(PlayerQuitEvent) Time: 39101 Count: 1 Avg: 39101 Violations: 0
        Task: PureEntitiesX v0.2.1_dev Runnable: revivalpmmp\pureentities\task\AutoDespawnTask(interval:500) Time: 75817 Count: 2 Avg: 37909 Violations: 0
        Task: PureEntitiesX v0.2.1_dev Runnable: revivalpmmp\pureentities\task\AutoSpawnTask(interval:300) Time: 2799749 Count: 3 Avg: 933250 Violations: 0
        ** can - doChunkUnload Time: 959635 Count: 26 Avg: 36909 Violations: 0
        ** can - doTickPending Time: 2259970 Count: 717 Avg: 3152 Violations: 0
        ** can - doTickTiles Time: 700130939 Count: 717 Avg: 976473 Violations: 0
        ** can - entityTick Time: 367599010 Count: 717 Avg: 512690 Violations: 0
        ** can - tileEntityTick Time: 4626989 Count: 717 Avg: 6453 Violations: 0
        ** can - syncChunkSend Time: 1850843 Count: 4 Avg: 462711 Violations: 0
        ** can - syncChunkSendPrepare Time: 1792669 Count: 16 Avg: 112042 Violations: 0
        ** can - syncChunkLoad Time: 107751369 Count: 28 Avg: 3848263 Violations: 1
        ** can - syncChunkLoad - Data Time: 105273962 Count: 28 Avg: 3759784 Violations: 0
        ** can - syncChunkLoad - Entities Time: 78917 Count: 28 Avg: 2818 Violations: 0
        ** can - syncChunkLoad - TileEntities Time: 47684 Count: 28 Avg: 1703 Violations: 0
        can - doTick Time: 1150447845 Count: 717 Avg: 1604530 Violations: 0
        ** receivePacket - BatchPacket [0x6] Time: 22193193 Count: 198 Avg: 112087 Violations: 0
        ** tickEntity - EntityPlayer Time: 59908628 Count: 428 Avg: 139973 Violations: 0
        ** sendPacket - SetTimePacket [0xb] Time: 92030 Count: 2 Avg: 46015 Violations: 0
        ** sendPacket - UpdateAttributesPacket [0x1f] Time: 119925 Count: 2 Avg: 59962 Violations: 0
        ** sendPacket - BatchPacket [0x6] Time: 326157 Count: 4 Avg: 81539 Violations: 0
        ** sendPacket - SetEntityDataPacket [0x28] Time: 321865 Count: 3 Avg: 107288 Violations: 0
        ** sendPacket - FullChunkDataPacket [0x3b] Time: 92983 Count: 16 Avg: 5811 Violations: 0
        ** sendPacket - AddEntityPacket [0xe] Time: 103951 Count: 1 Avg: 103951 Violations: 0
        ** sendPacket - MoveEntityPacket [0x13] Time: 25645494 Count: 566 Avg: 45310 Violations: 0
        ** receivePacket - MovePlayerPacket [0x14] Time: 9455204 Count: 199 Avg: 47514 Violations: 0
        ** receivePacket - PlayerActionPacket [0x25] Time: 1091242 Count: 15 Avg: 72749 Violations: 0
        ** sendPacket - DisconnectPacket [0x5] Time: 23127 Count: 1 Avg: 23127 Violations: 0
    # Version v1.0.5.0 beta
    # PocketMine-MP 1.6.2dev
    # Entities 2
    # LivingEntities 2
    Sample time 35849137068 (35.849137067795s)
    
    In the morning (no lag at all):
    Code:
    Minecraft
        Full Server Tick Time: 2910753965 Count: 732 Avg: 3976440 Violations: 4
        ** Full Server Tick Time: 2909493446 Count: 732 Avg: 3974718 Violations: 4
        Memory Manager Time: 2044439 Count: 733 Avg: 2789 Violations: 0
        Player Network Send Time: 198015928 Count: 3196 Avg: 61957 Violations: 0
        Player Network Receive Time: 61188936 Count: 452 Avg: 135374 Violations: 0
        Player Order Chunks Time: 2693653 Count: 29 Avg: 92885 Violations: 0
        Player Send Chunks Time: 117855072 Count: 8 Avg: 14731884 Violations: 2
        Connection Handler Time: 104314804 Count: 733 Avg: 142312 Violations: 0
        Scheduler Time: 15665531 Count: 733 Avg: 21372 Violations: 0
        Server Command Time: 6510735 Count: 732 Avg: 8894 Violations: 0
        ** entityMove Time: 276624203 Count: 3284 Avg: 84234 Violations: 0
        ** tickEntity Time: 971300602 Count: 733 Avg: 1325103 Violations: 0
        ** tickTileEntity Time: 1696110 Count: 733 Avg: 2314 Violations: 0
        ** entityBaseTick Time: 204926968 Count: 3776 Avg: 54271 Violations: 0
        ** livingEntityBaseTick Time: 67143440 Count: 733 Avg: 91601 Violations: 0
        ** Scheduler - Sync Tasks Time: 6092072 Count: 3 Avg: 2030691 Violations: 0
        ** Scheduler - Async Tasks Time: 1552343 Count: 733 Avg: 2118 Violations: 0
        Plugin: PureEntitiesX v0.2.1_dev Event: revivalpmmp\pureentities\event\EventListener::dataPacketReceiveEvent(DataPacketReceiveEvent) Time: 5679369 Count: 918 Avg: 6187 Violations: 0
        Plugin: PureEntitiesX v0.2.1_dev Event: revivalpmmp\pureentities\event\EventListener::entityDeathEvent(EntityDeathEvent) Time: 6914 Count: 1 Avg: 6914 Violations: 0
        Task: PureEntitiesX v0.2.1_dev Runnable: revivalpmmp\pureentities\task\AutoDespawnTask(interval:500) Time: 64850 Count: 1 Avg: 64850 Violations: 0
        Task: PureEntitiesX v0.2.1_dev Runnable: revivalpmmp\pureentities\task\AutoSpawnTask(interval:300) Time: 6021976 Count: 2 Avg: 3010988 Violations: 0
        ** can - doChunkUnload Time: 473022 Count: 17 Avg: 27825 Violations: 0
        ** can - doTickPending Time: 2096415 Count: 733 Avg: 2860 Violations: 0
        ** can - doTickTiles Time: 1337840796 Count: 733 Avg: 1825158 Violations: 0
        ** can - entityTick Time: 974171638 Count: 733 Avg: 1329020 Violations: 0
        ** can - tileEntityTick Time: 4343033 Count: 733 Avg: 5925 Violations: 0
        ** can - syncChunkSend Time: 10289907 Count: 8 Avg: 1286238 Violations: 0
        ** can - syncChunkSendPrepare Time: 10139942 Count: 32 Avg: 316873 Violations: 0
        ** can - syncChunkLoad Time: 218014717 Count: 41 Avg: 5317432 Violations: 2
        ** can - syncChunkLoad - Data Time: 215143442 Count: 41 Avg: 5247401 Violations: 2
        ** can - syncChunkLoad - Entities Time: 98705 Count: 41 Avg: 2407 Violations: 0
        ** can - syncChunkLoad - TileEntities Time: 475407 Count: 41 Avg: 11595 Violations: 0
        can - doTick Time: 2512626648 Count: 733 Avg: 3427867 Violations: 0
        ** receivePacket - BatchPacket [0x6] Time: 60394049 Count: 452 Avg: 133615 Violations: 0
        ** tickEntity - EntityPlayer Time: 144555330 Count: 733 Avg: 197211 Violations: 0
        ** sendPacket - SetTimePacket [0xb] Time: 190258 Count: 4 Avg: 47565 Violations: 0
        ** sendPacket - BatchPacket [0x6] Time: 680685 Count: 8 Avg: 85086 Violations: 0
        ** sendPacket - SetEntityDataPacket [0x28] Time: 157118 Count: 3 Avg: 52373 Violations: 0
        ** sendPacket - FullChunkDataPacket [0x3b] Time: 1797915 Count: 32 Avg: 56185 Violations: 0
        ** sendPacket - AddEntityPacket [0xe] Time: 417233 Count: 6 Avg: 69539 Violations: 0
        ** sendPacket - MoveEntityPacket [0x13] Time: 95063686 Count: 3133 Avg: 30343 Violations: 0
        ** receivePacket - MovePlayerPacket [0x14] Time: 28192520 Count: 456 Avg: 61826 Violations: 0
        ** receivePacket - PlayerActionPacket [0x25] Time: 387192 Count: 10 Avg: 38719 Violations: 0
        ** sendPacket - EntityEventPacket [0x1d] Time: 334740 Count: 9 Avg: 37193 Violations: 0
        ** sendPacket - RemoveEntityPacket [0xf] Time: 51022 Count: 1 Avg: 51022 Violations: 0
    # Version v1.0.5.0 beta
    # PocketMine-MP 1.6.2dev
    # Entities 7
    # LivingEntities 7
    Sample time 36646738052 (36.646738052368s)
    
    What is violations and what is the avg?
     
  12. Muqsit

    Muqsit Chicken

    Messages:
    1,548
    GitHub:
    muqsit
    Oh, you are using revival/PureEntitiesX.
    Anyways, as you can already say from your test that DataPacketReceiveEvent is messing up the most.
    Data events and entity movement events should never be handled poorly. These are some heavy events and are called way too many times.

    Never reinvent the wheel.
    That's exactly what's happening. Take a look here.
    Who on Earth thought it was a good idea to use DataPacketReceiveEvent for listening to interactions? That's just... :facepalm:
    There already exists a PlayerInteractEvent that is called way less amount of times and handles it much better.
    Ironically, whoever wrote the code, handles spawn eggs using PlayerInteractEvent, but uses DataPacketReceiveEvent to handle interactive button clicks.

    As for the AutoDespawnTask, let's just say it's some heavy coding. 3 foreach loops that could each contain from 1 to 200 values. Seriously, think of it. If you have 1 world, 200 entities (incl. Dropped items, player, etc), your server would just be dead-dead, as it is gonna loop 1*200*(maybe 40), around 8000 times, with no break function being called.
     
    jasonwynn10 likes this.
  13. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    Yes - told that in the first post already :)

    Thanks for analyzing this. I'll take a look into the issues you mentioned.

    The documentation of the API is very poor - so it's no wonder that events are used which are not designed to be used. But I'll take a look into it. Thanks a lot!

    Will also take a look at the despawn task. Maybe I can make it a little more performant :(

    This was the first answer, which has some real hints. Thanks for this. I will report back with questions or results :D
     
    Muqsit likes this.
  14. kniffo80

    kniffo80 Silverfish

    Messages:
    24
    GitHub:
    kniffo80
    So - I took a look at the PlayerInteractEvent:

    Code:
    /**
    * Called when a player interacts or touches a block (including air?)
    */
    class PlayerInteractEvent extends PlayerEvent implements Cancellable{
    
    When receiving this packet, how to get the entity interacting with? With DataPacketReceiveEvent you can get the entity with $event->getPacket()->target ....
     
  1. This site uses cookies to help personalise content, tailor your experience and to keep you logged in if you register.
    By continuing to use this site, you are consenting to our use of cookies.