Pocketmine-mp: Console becomes unresponsive after several hours idle.

[KAGsundaram]

Issue description

On both PocketMine-MP_1.6.1dev-73_794ff643_API-2.1.0 and PocketMine-MP_1.6.1dev-76_8214e50b_API-2.1.0, (Windows 10 Pro) after two or more hours of operation, unattended with no players in the game, upon returning to the console there is no response to commands. The game is still functioning, players may login and the world responds normally. However, at the console (the server terminal window), commands such as "list" or "version" are ignored. Characters typed appear on the screen, but without effect. Ctrl-C is recognized, terminating the program.

Steps to reproduce the issue

1. start.cmd
2. verify operation of console (terminal window) by issuing "version" command.
3. verify game operation by briefly logging in from Windows Phone 8.1 device.
4. exit device from game.
5. leave system idle for two hours.
6. attempt "version" command again.
7. verify game operation by logging in from gaming device.

OS and versions

• Title Bar: PocketMine-MP 1.6.1dev-#76 | Online 0/20 | Memory 16.11/0/16.11/20 MB @ 6 threads | U 0 D 0 kB/s | TPS 20 | Load 0.28%

• PocketMine-MP: PocketMine-MP_1.6.1dev-76_8214e50b_API-2.1.0

• PHP: PHP7.0.13

• Server OS: Windows 10 Pro

• Game version: PE

Crashdump, backtrace or other files

• ...

[robske110]

Is the title bar still updating (It probaby is, because you can join)
This issue is then most likely caused by the CommandReader Thread that has somehow lost stdin or readline malfunctions.

[KAGsundaram]

Yes, the title bar is still actively updating. Lots of action there.

[KAGsundaram]

It did it again.
This time I followed the suggestion of Awzaw and commanded "timings on".
The last entry in the server log is:

2016-11-15 [01:43:34] [Server thread/INFO]: Enabled Timings & Reset

[KAGsundaram]

I am running Build 76 again overnight. This time I set the debug level to 2. Perhaps this will generate useful information.

[SOF3]

Debug level 2 is unlikely to generate useful information.

[KAGsundaram]

Thank you. 2 yielded nothing new. same failure, no data.

[robske110]

https://github.com/robske110/pmmp-PocketMine-MP/tree/patch-1
try running from that source

[KAGsundaram]

It is time for me to slow down and be more scientific. More gets done faster that way.
Right now I am running the suggested Debug Level 3 test.
Next I would like to run a test with more PHP debugging.
(It looks like there are debug settings which can be turned on in php.ini; I could use some help/suggestions with this)

Then, @robske110, I would like to run your software. (Yes, I have Windows 10 Pro)
In order to be certain we are all "on the same page", some procedural questions:
@robske110, can you provide a link for PHP etc? (/bin/, /bin/php/) I want to be sure mine is exactly the same as yours.
For procedure, I expect to -
(1) Start a new folder with the /bin/ you name.
(2) Copy in the Build 76 phar.
(4) Run a stock Build 76 once.
(4) Overwrite with relevant files from https://github.com/robske110/pmmp-PocketMine-MP/tree/patch-1
(5) Run the test.

@robske110, please correct me on this if needed.

[dktapps]

There's no such thing as debug level 3. 1 is off, 2 is on. Stupid but true. #blameshoghi

[KAGsundaram]

Thanks, dktapps. Someone suggested...

[KAGsundaram]

A thought...

Someone has speculated "Out of Memory". I thought that this was impossible in my case, because I am using at maximum only 59% of my 8 GB.

However, in php.ini, I see a memory limit set to 256 MB. Perhaps this memory limit is being exceeded.

This problem has the classic symptoms of a "Memory Leak".

[KAGsundaram]

A quick search of "memory leak php" and "resource leak php" reveals that these issues continue to plague PHP applications.

Of particular interest is http://php.net/ChangeLog-7.php (Ctrl-F search the page for "leak")

[robske110]

@KAGsundaram this is not a memory leak. Stdin just likes to go missing. Please try my version, it only adds debug.

[archie426]

I can confirm this with the same version as @KAGsundaram . Though, I haven't begun to think about what is causing it. Although, in older versions of Pocketmine (I think Pocketmine Dev 1266 1.6 first release by @Intyre on the old forums) this bug was at large

[robske110]

this is a bug with stdin. I can reproduce it with this:

    public function __construct(){
        global $stdin;
        $stdin = fopen("php://stdin", "r");
        stream_set_blocking($stdin, 0);
    }

    public function run(){
        while(!$this->doExit){
            $foundInput = false;
            while(!$foundInput){
                global $stdin;
                sleep(1);
                $input = trim(fgets($stdin));
                if($input != NULL || $input != ""){
                    $foundInput = true;
                }else{
                    echo("[ERROR] Stdin corrupted!".PHP_EOL); //This message shows up roughly every 10 minutes 
                    $stdin = fopen("php://stdin", "r");
                    stream_set_blocking($stdin, 0);
                }
            }
            $this->processCMD($this->processRawInput($input));
        }
    }

Please do not add any more comments that are not helping to resolve this issue.

[KAGsundaram]

Well, it looks like php.ini has all possible debug (except php_xdebug.dll, and I am NOT going there today) turned on already, so I can skip that step.

Unless someone suggests a /bin/ link, and/or a /bin/php/ link, in the next few minutes, I will proceed with what I have.

I will proceed with the steps listed above and run @robske110 's software.

[KAGsundaram]

Proceeding.
Should detailed comments of the test be here or at #106 ?

[robske110]

they should be here, #106 has different code.

[KAGsundaram]

I am testing https://github.com/robske110/pmmp-PocketMine-MP/tree/patch-1

[KAGsundaram]

Procedure changed
(1) New Pocketmine-MP folder
(2) Copied in /bin/ and /bin/... subfolders from previous Pocketmine-MP folder.
(3) Copied in PocketMine-MP_1.6.1dev-76_8214e50b_API-2.1.0.phar as PocketMine-MP.phar
(4) Copied in all files, folders and subfolders from pmmp-PocketMine-MP-patch-1.zip
(5) Ran start.cmd

It is running now.

[robske110]

Wait, you need to use my modiefied code. Do not use PM's phar

[KAGsundaram]

patch-1 doesn't seem to include everything.
Do you have a phar?

[KAGsundaram]

Next test (proposed):

(1) New Pocketmine-MP folder
(2) Copy in /bin/ and /bin/... subfolders from previous Pocketmine-MP folder.
(3) Copy in PocketMine-MP_1.6.1dev-76_8214e50b_API-2.1.0.phar as PocketMine-MP.phar
(4) Run once to unpack needed files from the phar.
(5) Copy in all files, folders and subfolders from pmmp-PocketMine-MP-patch-1.zip to overlay files from the 76 phar
(6) Run start.cmd

[KAGsundaram]

Results of run WITHOUT the phar present (to avoid the phar overwriting patch-1 files):

[CRITICAL] Unable to find the PocketMine-SPL library.
[CRITICAL] Please use provided builds or clone the repository recursively.
bin\php\php.exe: Exit 1

[KAGsundaram]

Run again, with patch-1 files, and PocketMine-MP_1.6.1dev-76_8214e50b_API-2.1.0.phar as PocketMine-MP.phar

So far so good.
Does NOT run the startup wizard this time.

PocketMine-MP 1.6.1dev-#76 | Online 0/20 | Memory 16.12/0/16.12/20 MB @ 6 threads | U 0 D 0 kB/s | TPS 20 | Load 0.31%

We shall see how long the console remains responsive.

[KAGsundaram]

Console unresponsive after less than two hours.

No error messages, no debug output that I could find.

[robske110]

Ok, you were supposed to run only from src, not from a phar. Well, i'm going to compile a phar for youy

[robske110]

Try it with this phar:
(as PocketMine.phar)
PocketMine-MP_1.6.1dev.phar.zip
Unzip first!

[robske110]

Did you have time to do it yet?

[KAGsundaram]

PocketMine-MP_1.6.1dev.phar.zip has exhibited the same behavior.

[robske110]

PocketMine-MP_1.6.1dev.phar.zip
Try this new one!
It should display some stuff on startup including 'CommandReader->__construct()'. If that displays, you can be assured that you installed it correctly.

[KAGsundaram]

In a little bit.

Right now I have some outside work, aligning a Ka/Ku band satellite antenna before daylight fades.

[KAGsundaram]

The test is running now. See the message thread for details.

[KAGsundaram]

When the program starts, the response to the keyboard is normal, plus some very interesting debug output.
For example:

version
fgets:
string(8) "version
"
trim(fgets)

string(7) "version"

After two hours, the console is four lines of debug output repeated a seemingly infinite number of times:

fgets:
bool(false)
trim(fgets)
string(0) ""

---

By rapidly, repeatedly striking one key, for example "x", a quick eye will occasionally see the "x" flash by.

It seems that console lockup mode is a tight loop discarding all input characters.

[robske110]

Ok, it looks like it suddenly got non-blocking. Does it respond to your cmds at that stage? And if it really is throwing bool(false) in fgets at you, there is probably nothing ghat i can do.

[KAGsundaram]

Another identical test, same results, except at the end, I tested "Does it respond to your cmds at that stage?" by typing the "help" command. (Chosen because it is the command with the maximum console output.) There was no visible evidence that the command had been honored.

However, the program did respond properly to Ctrl-C.

Either the the program in this condition can only respond to single-character commands, or Ctrl-C is handled at a lower level, before characters are passed to this part of the program.

[robske110]

CTRL+C is handled by the system and sent to php

I actually managed to fix this issue, PR is going to be updated now

[ghost]

@robske110 why the windows sucks i use windows my consol dont froze and i use windows 10 pro

[robske110]

Windows sucks for development. That is a fact. There is no need to elaborate this any further.

[robske110]

Ouch. Please check properly before you do post usless comments.

[daterrell]

I think it's important to note that stream_set_blocking($stdin, 0); fails on Windows (at least in my case). I've gotten around this issue by adding the re-initialization of $stdin when it "disappears". The stop command will not actually stop the server until another newline is entered, but I can live with that. In the meantime, my console remains active for days, and the CommandReader thread mostly sits idle/blocked. fwiw, the sleep block is never hit in this case anyway.

[robske110]

Yes, we know that and I have done the same hack in PR #106.

[dktapps]

@daterrell See #25 also