IVM heap usage & game objects



  • 0_1524842925244_c161874d-3d06-4c3d-b866-377d52533186-image.png

    My heap is a lot more unstable after today. It reached thousands of ticks on the same global (purple line) before, but now its resetting a lot more often now.



  • @geir1983 said in IVM heap usage & game objects:

    My heap is a lot more unstable after today. It reached thousands of ticks on the same global (purple line) before, but now its resetting a lot more often now.

    I wonder what's going on there. The change was made at 12:30, right? I didn't see the 9:30 change on my plots, but I think you're on a different shard. It's the 9:30 change that seems to have messed something up for you.



  • This post is deleted!

  • Dev Team

    Just wait a day or two, it should calibrate itself after some time and become more stable.



  • My heap is still very unstable since the change 5 days ago. My CPU not really taking a hit, as my global is not completely reset, but somehow the heap is not stable for me anymore. Before this change my heap was stable and could reach thousands (20k+) of ticks between global resets. Edit: Im now reaching around 500 ticks before my global is reset.

    I do have vision in about 230 rooms, 30 owned room and about 1000 creeps if this is related.

    0_1525277608744_5b3d325c-18b6-4abe-a9f2-987eefe79926-image.png



  • @artch said in IVM heap usage & game objects:

    Just wait a day or two, it should calibrate itself after some time and become more stable.

    So my heap is getting worse and worse instead. Right now my globals last an average of 100 ticks, down from 20k+ when the size limit was increased. I am pretty sure i did not introduce any new caching etc on my end. This is now resulting in error messages and loss of ticks. I have attempted to disable my path caching without any noticable effect. My heap usage (total_heap_size + externally_allocated_size / heap_size_limit) jumps between 60%-90% every other tick.

    [8:31:40 AM][shard1]Error: Isolate was disposed during execution due to memory limit at () at runUser (/opt/engine/dist/core/runtime/make.js:164:34) at _tickDomainCallback (internal/process/next_tick.js:228:7) [8:31:43 AM][shard1]Script execution has been terminated: your isolate disposed unexpectedly, restarting virtual machine


  • Dev Team

    @geir1983 What happens if you remove your code and leave empty main? You can try to do that on another shard/PTR, if heap is stable in this case, then the problem is in your code.



  • @artch o i left my code running with an empty main for 180 ticks on shard 1, the heap is still jumping a lot, but it has a lower base line, now jumps between 55%-80% with no code running at all. Now my Observers/creeps are also not running so there is also less rooms in vision.

    The flat line at 09:30 was when i inserted a return as the first statement in my Main, without logging the heap stats.

    0_1525851660843_76e50808-25da-4a87-b16c-f0ba5a4a4f10-image.png


  • Dev Team

    @geir1983 Heap jumping is intended, it's how GC works. Do you have any errors with empty main?



  • I did not see any errors during my empty Main, but the errors were sporadic before. I left it for a while, but this short time already reduced my creep count from 1000 to 800, i did not want to continue running this test as the result were showing heap usage of up to 80% with no code running.

    My issue is that the heap was perfectly stable before the heap limit was increased. I do get that we have to take care of the heap usage in code, but if it was fine before the limit was increased, why is it now hitting the ceiling once it should have even more room?


  • Dev Team

    @geir1983

    result were showing heap usage of up to 80% with no code running.

    Again, it seems normal. Garbage collection may start running approximately at this point.

    My issue is that the heap was perfectly stable before the heap limit was increased. I do get that we have to take care of the heap usage in code, but if it was fine before the limit was increased, why is it now hitting the ceiling once it should have even more room?

    I think it's just a coincidence, raising heap limit itself shouldn't affect it this way, the real reason is elsewhere.



  • @artch said in IVM heap usage & game objects:

    result were showing heap usage of up to 80% with no code running.

    Again, it seems normal. Garbage collection may start running approximately at this point.

    I still think that running garbage collection every second tick even when my code is not running seems excessive, especially when it was running thousands of ticks without triggering at all before the change that increased the total heap available. It might be random and a coincidence, but to me it seems like it was introduced at that change, as shown in my previous posts.



  • @geir1983 is it possible that the change gave GC enough heap that it skips every other tick now, where previously it ran every tick? Wouldn't this have kept heap to a minimum every tick previously, while now it bounces around?



  • @Gankdalf I have no idea, it sounds plausible, but my graphs were atleast not showing this. I attempted to run gc() every tick to see if this worked like you suggested, but it destroys my bucket, the call costs 70-90 cpu. Is there a different version that is running in the background?



  • @geir1983 Does the automatic GC call count against your bucket if it is triggered by the Game object creation each tick (which is likely the cause of a lot of this issue in the first place)?


  • Dev Team

    You may try to call gc(true) to run scavenge only (minor collection cycle), it isn't full collection, but works very fast.

    😮


  • Calling gc(true) did cost a lot less, but it does not give me any noticeable effect (it was cleaning ~1mb for ~1 cpu). Calling gc() does clean my graphs (cleaning 10-50mb, for 60-90 cpu), but it cost so much that my bucket crashes pretty fast and the graphs was still not as smooth as it used to be. I could not let it run longer, because my bucket was emptied.

    Is it possible that the game was calling some other gc function in the background before and that it is free when the game calls this as opposed to the player calling it?

    09:15 - 09:35 calling gc(true), 09:35-09:38 calling gc(), 09:45-09-50 calling gc() 0_1525938888309_0d99cf22-23f2-49ea-b247-d9180a666816-image.png


  • Dev Team

    @geir1983 The game itself never calls gc explicitly, it is done automatically by V8.



  • Could it be that before the gc was hitting in a region of code outside of the userland CPU measurements and now it's hitting inside it? Not everything counts toward user CPU, so if GC previously reliably hit in game object creation (for example... I don't actually know if that's inside or outside the timing) and now with the extra size hits inside the user timed loop more often then you'd notice a big difference.

    👆


  • The scenario @Tigga described ^ is exactly what I see. Here's a graph of my CPU (top) and heap + Global Age (bottom) for the last week or so. You can see that my CPU usage drops steadily the longer my global has been alive. I believe this is because some small leak slowly changes the heap characteristics such that GC transitions from almost always happening during my user code (incurring massive CPU cost) to almost never happening during my code. I know it's a difficult problem, and I certainly don't have a solution, but I dream of not having to deal with the volatility of GC. I'm confident that the immortal Game object changes will help immensely.

    0_1526673964395_Screen Shot 2018-05-18 at 1.02.31 PM.png