Bentobox: Bentobox takes too much server's performance by blocking ender dragon spawn

[MorkaZ]

1.13.2 paper server & Latest Bskyblock&Bentobox for 1.13.2

[BONNe]

Hmm, ther could be improvements that does not change block, if it is endportal.

However it could take so much time just because it is paper, and paper already is blocking ender dragon but with other hacks.

You could try to disable REMOVE_END_EXIT_ISLAND world flag, and check again

[tastybento]

I will rearrange the checks so that the least intensive ones are done first so that the flag is checked last. I'm really surprised it's taking so long from those stats.

[MorkaZ]

It happens when chunks are being loaded first time.
Easy way to reproduce it is "/wb fill" command from worldborder or any world chunk generator.

[MorkaZ]

Will it be fixed in near future? It is downgrading my server's TPS very much :(

[BONNe]

So,
I did some tests ... and cannot confirm your results.
Yes, BlockEndDragon takes a lot of time... but just when world first chunk is created. Afterwards, it did not take any time at all.

Steps I did:
1-> turn off timings before starting the server.
2-> start server
3-> enable timings
4-> go to the end
5-> process world border fill with 10000 blocks in X and Z
6-> wait till it ends... and check report.

The reason why it takes time at startup so much is that Mojang removes the portal block on server stop, as it is not valid end portal, and on server startup, we need to restore it, to avoid spawning End Exit Portal over the first island.

[MorkaZ]

Then, I do not know what is triggering it. After filling I did timings paste and this is what I get. Those timings are from 60 minutes from filling (timings v2 allows you to select time interval).

Something is calling this event and this event takes too much time. If this lag was only on server start or world create then it could not take that much time to process.

[MorkaZ]

Were you testing it on paper spigot? Maybe their chunk loading queue is cause of this problem

[BONNe]

I tested on Paper-625 version with the default configuration.
Just with BentoBox and BSkyBlock, and World Border plugins.

Did not encounter any issues, and even event for me was called over 200 000 times (for each chunk) it did not affect performance at all.

I also added local debug output that checks nanoseconds for each if statement and it also shows that they are fast checks that do not affect performance.

The only issue that could happen is that somehow in your server that portal block is removed and each 0,0 chunk is unloaded/loaded multiple times.

Could you provide /bentobox voutput so I could test in the same environment that you have?

[BONNe]

@MorkaZ,
I suggested you to disable REMOVE_END_EXIT_ISLAND flag. Did you try it?
As if you disable this flag, then it will fail on the first statement and you could check if it still lags.

[tastybento]

Yes, this is really weird. @MorkaZ Can you share full details on what your server is running in terms of other plugins?

[MorkaZ]

@BONNe I have disabled it now. Also, today I have switched my server to normal spigot for a while to check if TPS will go down like before or not and check how it looks in old timings (v1).

My /bentobox v:

By the way.. This output is misleading because I have also loaded world BSkyblock_world_nether and BSkyblock_world_the_end

Plugins:

I will also post timings on the end of this day.

[Poslovitch]

This output is misleading because I have also loaded world BSkyblock_world_nether and BSkyblock_world_the_end

It is actually working as intended. I'll improve how it displays.

[tastybento]

@MorkaZ Okay, looking forward to seeing them.

[MorkaZ]

My server did not handle old spigot (too many random lag spikes). I have changed my server to paper because players could not play normally.
Here is timings from paper (generated few moments ago):
https://timings.aikar.co/?id=2ca41ac1195345049ed0f11d66fe337c

By the way.. Why this world "BSkyblock_world_the_end" took so much server's ticks? It is weird because players are very rarely here. There is also no redstone mechanisms and entities can be calculated in this world on fingers.

Is it possible to disable end islands and unload this world without reseting database?
End islands feature has actually some problems that I can not pass through.

[BONNe]

Yes, just disable it in BSkyBlock config.

But it is weird, why it laggs so much.
One thing you could try, is disabling WorldGuard protection in these worlds, as BentoBox handles protection itself.

[MorkaZ]

Here are timings from today's morning:
https://timings.aikar.co/?id=5a4190f035764925825572646c6365a0
I did not disable end islands yet but as you can see in this timings, this world do not take now that much ticks from server, so something must trigger it.
I will try to do some tests in this world today (for example spawn end dragon by placing some end crystals) and I will post my results.

EDIT:
2 days before I have disabled lightning queues in paper because it had sometimes top ticks usage. Now it does not show up in timings but it may be related with this world. Probably sort of this type calculations went to worlds so maybe this "bskyblock_world_the_end" was doing somewhere a lot of light updates?

As you can see in previous timings, basic processes did not took many ticks but something that is undefined and it may be light update. Second thing is that "tickEntities" also took so many time and it has same problem as above - it is not defined what took that much ticks. I bet that it is related to ender dragon spawn and world's light updates when it tries to spawn dragon & update portal but something is cancelling this event and server is trying to do it again and again.

[MorkaZ]

After some time, high server's tick consumption from world "bskyblock_world_the_end" appeared again.
https://timings.aikar.co/?id=29debe252bc04c8d87bb6adbef3335d9

In this world to this time there were only 7 players that only visited their end island by portal creation (checked using my test logger created using "skript" plugin). Their island is default or very little modified. I think it is being triggered when player visits this world.

Worth to note is also fact that on my server is another end world called "end" and this world does not have problems like this. It is normal end world with 3000x3000 border to allow players get resources of this world.

[Poslovitch]

That's been a very long time since I read timings, but I can't find what in BentoBox would be causing the high server tick consumption related to the BSkyBlock's End world.

This is the only high ticking consumption I'm seeing - and it is not related at all to BentoBox - it's Minecraft.

And it actually looks like BentoBox is one of the most lightweight thing that listens to ChunkLoadEvent.

[MorkaZ]

Please, read my posts.

Those things are from minecraft server's api (ticking) so it is normal that they are not marked as plugin's consumption.
If, for example, plugin will load chunk, then in timings you will notice pct increase in "Minecraft::world_name - chunk load" and if other plugin is listening to this event then you will see procentage participe in ticks of this plugin.

So, if plugin is lagging using server's api then it will be hard to detect just by using timings and if plugin will lagg using its own api then it will be visible in timings that this plugin is source of tick consumption.

Here is example:
If plugin is preventing chunk load but server forces it then you will see in timings how much time it took for plugin to prevent chunk load * times (usually very small amount of time) in timings and (in top records) how much time it took for server to load chunk again and again and so on..

So in this case it match perfectly to this problem. Other end world does not lag even if there is much more players on this world than on bskyblock's end islands. Also, there is almost no entities in this world and usually 0-2 players (when on server is 100~ players online).

[Bisqus88]

I noticed same problem while using this plugin. I can not get rid off it too...

[tastybento]

@MorkaZ In the last set of timings, I don't see any reference to the BlockEndDragon code so that's not the issue.

Do you have any theories? I can make you a build with the Dragon code completely removed if you like to try. What version of BentoBox are you using right now?

[MorkaZ]

As you should notice, listed things are only mini part of all. Something is just not listed (just sum percents). Timings are just not very detailed statistics that can not tell you everything. I have typed why you could not see any plugin name here.

[tastybento]

I am not saying there isn't a problem, I am just perplexed as to why it is happening. In our code there are only two places where we bother with chunk loading - the dragon and clean super flat. Other than that, there is no influence. Try disabling fix super flat flag and see what happens.

Apart from that, there isn't much more we can do. How about you share your exact setup? I don't see that in your report. (System OS, Java version, plugins, version numbers) Then maybe we can try to replicate the issue.

[MorkaZ]

I think the cause is that you are trying to do something unsuported/different in end type world (Clearing everything from this world, including dragon related things). Server is ticking this world like crazy when there is nothing to tick. Probably it is not generated by your plugin itself but it is caused by it.

[BONNe]

So,
As I already wrote, if you disable REMOVE_END_EXIT_ISLAND flag, then it should not do anything, and even if active, it will affect only on world startup as THE_END 0,0 chunk is always loaded in 1.13.2 and 1.14.1 / 1.14.2 (I am not sure if you even can disable loading them).

It is like adding true and false to if statement. The only performance loses there is to find the value of this flag. (and in the worst case, it is nLog(n))

Ofcorse, BentoBox has other listeners too, that regulates block placing/breaking/interaction.
In the tick outputs, they do not take time, but as you explain, they can be also be not displayed correctly as this is not a profiler.

I will add some local outputs for testing performance, but could you also test performance when you disable World Guard and NoCheat in end world?

[MorkaZ]

I have disabled this end type world with islands and now everything is ok. As I said, I have disabled this flag and as I noticed in previous comment, this plugin is not SOURCE of lags in this world but may be CAUSE of it (not including this high pct with blocking ender dragon spawn).

Here is very simple example - if you will create plugin that will spawn 10k entities in 1 chunk then in timings you will not see your plugin entity spawn method but world's entity ticking process with highest pct. Timings is bad tool to search CAUSE of lags but it is good to search SOURCE of it. In this example case source of lag are entities but it is caused by plugin that spawned them.

In this case bskyblock could change something nessesary in end world and server is ticking it like crazy. Maybe because server cant find end portal? I do not know and I am unnable to test it now.

I hope I have explained in propetly because english is not my main language and it is hard for me to present my meaning good enough.

[BONNe]

So, BentoBox does not try to spawn any entity. It just checks if an entity is spawnable, and cancels spawning if it is by island rules. (f.e. disable hostile mob spawning).

Probably it creates this lag, as mob spawning are cancelled if flags are enabled. But then also WolrdGuard should be the same issue, as process how mob spawning is cancelled is the same.

And stop saying that blocking ender dragon is an issue. IT IS NOT. The portal frame is created just once, on world init, and it does not despawn or destroyed.

I know that paper blocks ender dragon by adjusting boolean check if portal exists. (Legacy check), but it is not possible to do in Spigot. So the only way how to trick Spigot is by adding an existing portal.
And as it is located in 0,255,0 position it is not affecting performance for searching, as it is always in the first chunk that is checked.

It is possible, that Paper Ender Dragon Legacy block may cause issues, but that's the Paper issue, not BentoBox.

[MorkaZ]

With dragons and portals it was only suggestions. Problem is probably with minecraft server and it is extremly hard to find out what is exactly causing it. Something weird is happening with this bskyblock's end world and I am out of ideas how to reproduce it. My last idea is that probably generating end world with only air is generating this weird ticking.

[tastybento]

@MorkaZ i think you may be right. It’s something in the server that is reacting to the void world type maybe. One approach could be to put a Java profiler on the server when it’s in this weird ticking mode and see what classes are causing it. I’ll see if I can get the server into this mode and see what happens but for now there is not a lot we can do on our end. Oh incidentally, there is an option for a sea in the end too. But I suspect is something to do with end mechanics.

[MorkaZ]

Here is 5 minutes profile from yesterday when TPS were low and top 2 values in timings were ticking of end world
profile.txt

[tastybento]

Thanks. I'll need to process that. From a quick scan, it looks like you're using MariaDB? The async code for MariaDB was only recently added for 1.5.0 so the saveAll can block the server. Change the database backup period to something large like 3600 in bentobox's config.yml and see if that helps at all. It may be irrelevant.

[tastybento]

I looked through the profile and about 3/4 of the way through there starts a lot of redstone events and subsequent physics updates of blocks. If you scroll through it you can't miss it. I'm not sure if that's anything, but just the size of it looks suspicious.
I am not an expert of this though. All in all, I'm not sure what else we can do here, so I'm just going to move this to monitoring and if we find something actionable we can do it.

[MorkaZ]

I have found another laggy thing:

[tastybento]

I assume you're referencing the LockAndBanListener? Do you have a lot of teleporting going on? What's weird there is that class also listens to every movement event, which would usually be occurring way more that teleporting, but it's the teleporting event that is called out. Strange.

[MorkaZ]

Players are teleporting using server commands like /is, /spawn, /warp, /home, /tpa. Also, they can not spam. I have also installed bskyblock's addon "warps-1.4.0" for teleportation.

It is hard to say what exactly caused it because it was ~120 players online in this time.