Pocketmine-mp: The world is infinitely unloading.

Created on 27 Jan 2018 · 50Comments · Source: pmmp/PocketMine-MP

Issue description

The server freezes without cause and other errors in the unloading of the world. Another strange thing is that the process no longer exists.

OS and versions

PocketMine-MP: 41592a04b7d0124d155ea6d99be8f11fe14d1de1
PHP: 7.2.1
Server OS: Linux Debian 8.6 jessie

Plugins

DevTools v1.12.7, ModalFormsAPI v1, clans v1, quests v1, DonateCases v1, RegionGuard v1.0.0, area v1, Kits v1.0.0, Shop v1, Economy v1, MineReset v3, PurePerms v1.4.0-INDEV, Evaluator v0.0.1, Horses v1.0.0, ToyBox v1, API v1.0.0, PureChat v1.4.0

PHP (extension) Hack-fixed

Source

Frago9876543210

👎1

Most helpful comment

I've reproduced the bug - calling Item::initCreativeItems() during onEnable() of a POSTWORLD plugin will trigger the bug (thank you @daniktheboss )

I did some digging into this and it appears to be a problem with the way pthreads handles static members. On further investigation I found a variety of interesting issues including heap corruption.

This will be reported upstream.

dktapps on 24 Apr 2018

👍5

All 50 comments

does it happen without any players too?

Muqsit on 27 Jan 2018

it would be appreciated if you could reproduce this with debug output enabled.

dktapps on 27 Jan 2018

@dktapps you mean X debug?

Frago9876543210 on 27 Jan 2018

no, I mean debug log level in pocketmine.yml

dktapps on 27 Jan 2018

I can also add that this shit started to happen after January 18-19. Prior to this, with 84 players, the server did not freezes in unloading of the world.

Frago9876543210 on 27 Jan 2018

@Frago9876543210 please watch your language.

It would be more helpful to know after which versions the bug started to occur. Also:

plugins? specifically if you're using TeaSpoon then no support can be provided
is the bug consistent or random?

dktapps on 27 Jan 2018

😕1

@dktapps

Plugins list added.
The error occurs entirely by accident. It is impossible to predict when it will happen.

Frago9876543210 on 27 Jan 2018

you're running Evaluator on a production server? 💀

dktapps on 27 Jan 2018

👀1

Yea. This is a very useful thing. For example, to fix some errors without rebooting.

Frago9876543210 on 27 Jan 2018

I also encountered such a problem, however, it was only once.

zKoz210 on 27 Jan 2018

I also have this problem random happen when the server stop
My Server Log with debug open :

[08:56:26] [Server thread/DEBUG]: Unloading all levels
[08:56:26] [Server thread/INFO]: Unloading level "lobby"
[08:56:26] [Server thread/INFO]: Unloading level "nether"
[08:56:26] [Server thread/INFO]: Unloading level "ender"
[08:56:26] [Server thread/INFO]: Unloading level "resources02"
[08:56:26] [Server thread/INFO]: Unloading level "resources01"
[08:56:26] [Server thread/INFO]: Unloading level "residence01"
[08:56:26] [Server thread/DEBUG]: Removing event handlers
[08:56:26] [Server thread/DEBUG]: Stopping all tasks
[08:56:26] [Server thread/DEBUG]: Closing console
[08:56:26] [Server thread/DEBUG]: Stopping network interfaces

And my server cpu usage always 100 % when this happen

xinghao2003 on 27 Jan 2018

If someone can reproduce this with debug logging enabled, or offer ways to reproduce this, it would be much appreciated. I have never encountered this issue.

dktapps on 27 Jan 2018

Another strange thing is that the process no longer exists.

correction - it's just not bound to port 19132 anymore, which would indicate that RakLib's socket has closed (due to shutdown).

dktapps on 27 Jan 2018

I Have this with the asyn branch

Op 27-jan.-2018 14:56 schreef "Frago9876543210" notifications@github.com:

Issue description

The server freezes without cause and other errors in the unloading of the
world. Another strange thing is that the process no longer exists.
[image: im]
https://camo.githubusercontent.com/5e7d0a3782299832531a8c1e8ea2162bce0f4a9e/68747470733a2f2f736e61672e67792f676c397836472e6a7067
OS and versions

PocketMine-MP: 41592a0
https://github.com/pmmp/PocketMine-MP/commit/41592a04b7d0124d155ea6d99be8f11fe14d1de1

PHP: 7.2.1

Server OS: Linux Debian 8.6 jessie

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
https://github.com/pmmp/PocketMine-MP/issues/1974, or mute the thread
https://github.com/notifications/unsubscribe-auth/APEEPuTGkYyJEi-oq9Xou0l0XdRueS_hks5tOysngaJpZM4RvTRc
.

Driesboy on 27 Jan 2018

For me, this happens when I have a plugin which removing items from creative inventory. I catched this problem about 2 month ago (nov. 2017).

UPD: maybe not because of plugin which removing items from creative inventory. Maybe because of plugin which removing items from creative inventory THAT IS NOT EXISTS (talking about items)

Yexeed on 27 Jan 2018

Do you use removeCreativeItem or unregisterCommand functions?

xISRAPILx on 28 Jan 2018

Unless you have something constructive to add to the discussion, please take the conversation elsewhere. This is not a support forum. Anything which does not directly pertain to the reported issue does not belong here.

dktapps on 28 Jan 2018

😄1

@dktapps After using these functions, I have the same problem.

Sorry, bad English

xISRAPILx on 28 Jan 2018

@dktapps

Frago9876543210 on 29 Jan 2018

so RakLib is getting stuck for some reason. Thanks @Frago9876543210 .

dktapps on 29 Jan 2018

@Frago9876543210 would you mind making some modifications to RakLib and add some debug output into this function? https://github.com/pmmp/RakLib/blob/master/server/ServerHandler.php#L70-L78

It appears that RakLib is getting stuck while shutting down, but it is unclear why.

dktapps on 29 Jan 2018

@dktapps ok. What add?

Frago9876543210 on 29 Jan 2018

Add some echo or var_dump() messages so that I can see what point it's getting stuck at.

dktapps on 29 Jan 2018

like this?

Frago9876543210 on 29 Jan 2018

that should be fine, yes.

dktapps on 29 Jan 2018

👍1

Can this log be used ?

[17:50:50] [Server thread/DEBUG]: Unloading all levels
[17:50:50] [Server thread/INFO]: Unloading level "lobby"
[17:50:50] [Server thread/INFO]: Unloading level "nether"
[17:50:50] [Server thread/INFO]: Unloading level "ender"
[17:50:50] [Server thread/INFO]: Unloading level "resources03"
[17:50:50] [Server thread/INFO]: Unloading level "resources02"
[17:50:50] [Server thread/INFO]: Unloading level "resources01"
[17:50:50] [Server thread/INFO]: Unloading level "residence01"
[17:50:50] [Server thread/DEBUG]: Removing event handlers
[17:50:50] [Server thread/DEBUG]: Stopping all tasks
[17:50:50] [Server thread/DEBUG]: Closing console
[17:50:50] [Server thread/DEBUG]: Stopping network interfaces
#1
#2
#3
#4
#5
Done

xinghao2003 on 4 Feb 2018

that's strange indeed... so it's not RakLib at all...

@xinghao2003 am I correct to assume that your server is then stuck after "done"?

dktapps on 4 Feb 2018

Yes

xinghao2003 on 4 Feb 2018

that's very odd... hmm... I'm not sure what else could cause this.

dktapps on 4 Feb 2018

I've pushed a commit to add additional debug for server shutdown. Please try it and report back where issues occur.

dktapps on 4 Feb 2018

Latest Log

[19:18:07] [Server thread/DEBUG]: Unloading all levels
[19:18:07] [Server thread/INFO]: Unloading level "lobby"
[19:18:07] [Server thread/INFO]: Unloading level "nether"
[19:18:07] [Server thread/INFO]: Unloading level "ender"
[19:18:07] [Server thread/INFO]: Unloading level "resources03"
[19:18:07] [Server thread/INFO]: Unloading level "resources02"
[19:18:08] [Server thread/INFO]: Unloading level "resources01"
[19:18:08] [Server thread/INFO]: Unloading level "residence01"
[19:18:08] [Server thread/DEBUG]: Removing event handlers
[19:18:08] [Server thread/DEBUG]: Stopping all tasks
[19:18:08] [Server thread/DEBUG]: Closing console
[19:18:08] [Server thread/DEBUG]: Stopping network interfaces
[19:18:08] [Server thread/DEBUG]: Stopping network interface pocketmine\network\mcpe\RakLibInterface
#1
#2
#3
#4
[19:18:08] [RakLibServer thread/DEBUG]: Closed session for 115.132.200.23 55710
#5
Done
[19:18:08] [Server thread/DEBUG]: Stopping network interface specter\network\SpecterInterface
[19:18:08] [Server thread/DEBUG]: Collecting cycles

xinghao2003 on 4 Feb 2018

hmmmmmm... you're never seeing "stopping other threads"...

could you add some debug output after this line?
https://github.com/pmmp/PocketMine-MP/blob/master/src/pocketmine/Server.php#L2106

and in these lines:
https://github.com/pmmp/PocketMine-MP/blob/master/src/pocketmine/PocketMine.php#L556-L569

dktapps on 4 Feb 2018

Okay, It still stuck at Collecting cycles

xinghao2003 on 4 Feb 2018

this might be a GC issue in PHP then. This is very difficult to debug without being able to reproduce it myself.

If anyone would care to try and reproduce this without plugins, it would be appreciated.

dktapps on 4 Feb 2018

I've been facing this error too for the past couple of days, except it's been more severe just this week. I see you are running PHP 7.2.1 and I was too. I know this sounds really stupid as I don't have any exact justification for this but upgrading to PHP 7.2.2 solved this for me. I've not got any issues with PHP 7.2.2 so far. Can you upgrade your PHP and see if the problem persists?

Muqsit on 5 Feb 2018

I will try it, thanks

xinghao2003 on 5 Feb 2018

This issue still happen in PHP 7.2.2

xinghao2003 on 5 Feb 2018

Seems like PHP 7.2.2 make this issue happen every time I stop the server and maybe this was really a GC issue in PHP because it more serious in newer PHP version

xinghao2003 on 5 Feb 2018

Please try it without plugins. I cannot reproduce this bug at all, so while it might well be a PHP bug, whatever is triggering the bug needs to be isolated if possible.

dktapps on 5 Feb 2018

@xinghao2003 not only on 7.2.2. I got this error with php 7.2.0 & 7.2.1

Frago9876543210 on 5 Feb 2018

Reproduced again

daniktheboss on 11 Apr 2018

Simply saying you reproduced it is not helpful in the slightest. I need to know under what circumstances it was reproduced and what triggered it.

dktapps on 11 Apr 2018

👍3

@Frago9876543210 Do you have a plugin that registers or uses a custom world generator?

Muqsit on 11 Apr 2018

@Muqsit no. I can also note that this error was on the old hosting with low ghz per core.

Frago9876543210 on 11 Apr 2018

If I try to unload with a player on the server and in that world, it works fine. Without player it doesn't unload.

daniktheboss on 11 Apr 2018

I've reproduced the bug - calling Item::initCreativeItems() during onEnable() of a POSTWORLD plugin will trigger the bug (thank you @daniktheboss )

I did some digging into this and it appears to be a problem with the way pthreads handles static members. On further investigation I found a variety of interesting issues including heap corruption.

This will be reported upstream.

dktapps on 24 Apr 2018

👍5

Upstream PR'd test case (no fix): https://github.com/krakjoe/pthreads/pull/861

dktapps on 24 Apr 2018

This has not been fixed in pthreads but may have been resolved by recent changes on the master branch (no child threads in PocketMine-MP inherit loaded classes anymore), could someone confirm?

Note that this doesn't account for threads started by plugins.

dktapps on 13 Jun 2018

Closing this since it doesn't occur any longer (unless using custom threads, which is a bug for pthreads to fix).

dktapps on 6 Jul 2018

I have it again on 4.0
Note: My server use outdated PM 0ba3121c436206d86377b41120bf1a7266c3416d
Before was same with RconServer plugin