Servers automatically restarting and nonresponsive UI


#1

I’m running into an issue where my MC servers regardless of profile seem to be automatically shutting down and in some cases restarting within minutes. In addition the server UI becomes unresponsive to the point that I have to re-login to manage the servers every few minutes.

What this looks like from the in-game perspective is people get booted every few minutes off the server saying connection closed. To test this I spun up a vanilla server with no mods and noticed over time 2015-11-08-X.log.gz were being generated without user intervention on the web UI. So I’ve ruled out firewall, mods, and Crontab Schedule.

commit b19f851e5aa94eb53234ccd99e3509ea5c0441a2

A sample from the mineOS.log

proxy.log.0","timestamp":"2015-11-09T00:00:23.012Z"}
{"level":"info","message":"[ServerLive] Discovered server","timestamp":"2015-11-09T00:00:23.101Z"}
{"level":"info","message":"[ServerLive] Created tail on logs/latest.log","timestamp":"2015-11-09T00:00:23.102Z"}
{"level":"error","message":"[ServerLive] Create tail on server.log failed","timestamp":"2015-11-09T00:00:23.102Z"}
{"level":"info","message":"[ServerLive] Watching for file generation: server.log","timestamp":"2015-11-09T00:00:23.102Z"}
{"level":"error","message":"[ServerLive] Create tail on proxy.log.0 failed","timestamp":"2015-11-09T00:00:23.102Z"}
{"level":"info","message":"[ServerLive] Watching for file generation: proxy.log.0","timestamp":"2015-11-09T00:00:23.102Z"}
{"level":"info","message":"[TestingGrounds] Discovered server","timestamp":"2015-11-09T00:00:23.104Z"}
{"level":"info","message":"[TestingGrounds] Created tail on logs/latest.log","timestamp":"2015-11-09T00:00:23.104Z"}
{"level":"error","message":"[TestingGrounds] Create tail on server.log failed","timestamp":"2015-11-09T00:00:23.104Z"}
{"level":"info","message":"[TestingGrounds] Watching for file generation: server.log","timestamp":"2015-11-09T00:00:23.105Z"}
{"level":"error","message":"[TestingGrounds] Create tail on proxy.log.0 failed","timestamp":"2015-11-09T00:00:23.105Z"}
{"level":"info","message":"[TestingGrounds] Watching for file generation: proxy.log.0","timestamp":"2015-11-09T00:00:23.105Z"}
{"level":"info","message":"[TestingGrounds] eula.txt detected: ACCEPTED (eula=true)","timestamp":"2015-11-09T00:00:23.621Z"}
{"level":"info","message":"[ServerLive] eula.txt detected: ACCEPTED (eula=true)","timestamp":"2015-11-09T00:00:23.622Z"}
{"level":"info","message":"[ServerTest] autostart = false","timestamp":"2015-11-09T00:00:27.563Z"}
{"level":"error","message":"[ServerTest] Aborted server startup; condition not met: true","timestamp":"2015-11-09T00:00:27.564Z"}
{"level":"info","message":"[ServerLive] autostart = true","timestamp":"2015-11-09T00:00:27.566Z"}
{"level":"info","message":"[ServerLive] Server started. Waiting 10000 ms...","timestamp":"2015-11-09T00:00:27.702Z"}
{"level":"info","message":"[TestingGrounds] autostart = false","timestamp":"2015-11-09T00:00:37.702Z"}
{"level":"error","message":"[TestingGrounds] Aborted server startup; condition not met: true","timestamp":"2015-11-09T00:00:37.702Z"}

Full mineOS.log

  1. TestingGrounds is a vanilla server and stops within a few minutes of running and stays stopped until started through the web UI. Does not have Start server on boot checked.

  2. ServerLive seems to automatically restart itself even though it’s not set up to do such. Does have Start server on boot checked.


#2

Your mineos.log is littered with the same error:

{“date”:“Sun Nov 08 2015 23:35:07 GMT-0600 (CST)”,“process”:{“pid”:26499,“uid”:0,“gid”:0,“cwd”:"/",“execPath”:"/usr/bin/nodejs",“version”:“v5.0.0”,“argv”:["/usr/bin/nodejs","/usr/games/minecraft/webui.js",“start”],“memoryUsage”:{“rss”:176009216,“heapTotal”:62899968,“heapUsed”:30355760}},“os”:{“loadavg”:[0.34033203125,0.43798828125,0.36279296875],“uptime”:206956},“trace”:[{“column”:7,“file”:"/usr/games/minecraft/node_modules/fireworm/lib/file.js",“function”:null,“line”:45,“method”:null,“native”:false},{“column”:15,“file”:“fs.js”,“function”:“FSReqWrap.oncomplete”,“line”:82,“method”:“oncomplete”,“native”:false}],“stack”:[“AssertionError: File should always be initialied with stat”," at /usr/games/minecraft/node_modules/fireworm/lib/file.js:45:7"," at FSReqWrap.oncomplete (fs.js:82:15)"],“level”:“error”,“message”:“uncaughtException: File should always be initialied with stat”,“timestamp”:“2015-11-09T05:35:07.975Z”}

Can you verify there are no other servers (remnants of other servers) in the following directories?

/var/games/minecraft/archive
/var/games/minecraft/backup
/var/games/minecraft/servers

We expect [TestingGrounds] and [ServerLive]–are there any other directories there?

Also, in order to fix this issue, I need to be able to reproduce it. If there are any errant servers and files within, please take full note of what they are and relay this information to me. If just blindly deleting the files works, it still won’t bring the codebase any closer to detecting/resolving this issue automatically should it arise in the future.


#3

I verified over FTP. There is another server present in the directories you described. [ServerTest]
[ServerTest] shows up in the Web UI. was created but never used.

/var/games/minecraft/servers/ServerTest contains


/var/games/minecraft/backup/ServerTest does not contain any files or folders.
/var/games/minecraft/archive/ServerTest does not contain any files or folders.

I’ve included Files and folders including subdirectories from /var/games in an effort to provide you with the conditions to aid you reproducing it on your set up.


#4

Hrm, if ServerTest is not important, feel free to delete it and see if anything is resolved. I’ll try to reproduce your environment on one of my servers and see if I can get a similar repeated-crashing.


#5

I’ve included the my files in the post above to expedite reproducing conditions.

Edit: based on what you’ve seen thus far does this account for the web UI being slow or nonresponsive and the servers stopping themselves restarting depending if they have Start server on boot checked?

I have to ask myself the question why does one server simply just stop itself and the other restart itself?


#6

I should also mention that with the exception of the vanilla server. I’m not using profiles. Simply drag-and-drop the mods into the created server folder then selected the runnable jar. It seems that the web UI does not ever remember the runnable jar or profile setting. I have to select them each time I login and logout per server.

It’s hard to tell when the server UI is become unresponsive and if what I’m experiencing above is a side effect.

Edit
Removing ServerTest did not solve the issue.
I’m going to stop MineOS from command line then delete the MineOS.log. Then Restart MineOS and try from there.


#7

No, based on what you’ve described, there is nothing that explains the unresponsiveness or the servers stopping themselves. In fact, there’s very little connection between the servers once they are started–they’re a separate, non-child process to the webui.

Try this:

cd /usr/games/minecraft
git checkout 59d1e763746dc4494c531e5334626fe033819f23

Restart the webui and see if the problem persists. If it starts working, I’m pretty sure I have a good lead.


#8

The web-ui doesn’t need to “remember” the runnable-jar. All that information gets saved in server.config, which is what is used when the server tries to get started altogether. That means that even if the profile and runnable-jar values are EMPTY (no selection), it should not stop proper startup of the server itself via the start button, because it gets the values it needs from the server.config, in the background.


#9

I regret to report that it did not solve the issue.

Have you tried taking the files I uploaded and dumping them into a testing environment? I’m curious to see if it produces the same result.

My testing methods include.
Opening up the servers through FTP deleting the logs for each server than start the servers. Then waiting 10 minutes or so.

The typical result with the unresponsive web UI.

TestingGrounds is a vanilla server and stops within a few minutes of running and stays stopped until started through the web UI.

ServerLive always seems to be running even through the web UI but in reality it reboot itself. That is made evident when you look in the logs folder and see Multiple 015-11-XX-X.log.gz files. Each one represents a reboot. 

Another tactic is to restore a previous image. Then try testing from there. Reflecting on my previous post the could very well be the same situation. Which is odd because I’m now using Ubuntu 15.10 and everything was reinstalled from scratch.

Edit only thing in common is the same ModPack that I’ve compiled.


#10

Having no problems with the 7z file you provided. All servers appear in the webui and operate as expected; the ServerLive starts upon boot. I created a mineos_admins group and have been able to reassign servers to have mineos_admins group ownership.

One thing to note, however, is that 7z actually deletes permissions. Upon extraction on my Ubuntu box, the servers the directories looked like this:

drwx------ 5 will will 4096 Nov  9 14:44 archive
drwx------ 5 will will 4096 Nov  9 14:44 backup
drwx------ 2 will will 4096 Nov  9 12:27 import
drwx------ 4 will will 4096 Nov  9 14:44 profiles
drwx------ 5 will will 4096 Nov  9 14:44 servers

This means that the permissions and ownership information was lost when it showed up on my machine. It was auto-chowned to will because that was my user, but as you can see its chmod 700, which I had to change manually–and recursively.

That also means I have no idea whether the problem you are having is caused by inconsistent permissions, such as if some files inside servers/ServerLive/* were mis-owned. I blanket chmodded 664 to everything, and also to the user will, which again could possibly mask an actual issue you have if your files are not perm’ed right.

will@willonubuntu:/var/games/minecraft/servers$ groups will
will : will adm cdrom sudo dip plugdev lpadmin sambashare mineos_admins

#11

Have you looked inside the contents of each of these log files to see if they are showing any errors or issues?

I’m actually thinking the reverse causality. Perhaps Minecraft is crashing at whatever frequency of your logs…and MineOS isn’t able to handle polling the server or other actions (e.g., commit world via saveall) because the server is down/crashed/restarting.


#12

I’ve opened up most of logs and this is pretty representative. Typically when minecraft crashes a separate log is generated. I don’t believe this is the case with the situation as I’m not seen many crash logs generated nor did you see it during your testing. I’ve had some crashes but I should be having a crash every time a log is generated and it doesn’t explain why the vanilla server’s being stopped.

Random sample log 1

  [16:28:16] [Server thread/INFO]: Starting minecraft server version 1.8
    [16:28:20] [Server thread/INFO]: Loading properties
    [16:28:20] [Server thread/INFO]: Default game type: SURVIVAL
    [16:28:20] [Server thread/INFO]: Generating keypair
    [16:28:20] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
    [16:28:21] [Server thread/INFO]: Preparing level "world"
    [16:28:21] [Server thread/INFO]: Preparing start region for level 0
    [16:28:22] [Server thread/INFO]: Done (0.749s)! For help, type "help" or "?"
    [16:28:22] [Server thread/INFO]: Starting GS4 status listener
    [16:28:22] [Query Listener #1/INFO]: Query running on 0.0.0.0:25565
    [16:29:11] [Server Shutdown Thread/INFO]: Stopping server

Random sample log 2

[16:15:13] [Server thread/INFO]: Starting minecraft server version 1.8
[16:15:17] [Server thread/INFO]: Loading properties
[16:15:17] [Server thread/INFO]: Default game type: SURVIVAL
[16:15:17] [Server thread/INFO]: Generating keypair
[16:15:17] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
[16:15:19] [Server thread/INFO]: Preparing level "world"
[16:15:19] [Server thread/INFO]: Preparing start region for level 0
[16:15:19] [Server thread/INFO]: Done (0.845s)! For help, type "help" or "?"
[16:15:19] [Server thread/INFO]: Starting GS4 status listener
[16:15:19] [Query Listener #1/INFO]: Query running on 0.0.0.0:25565
[16:25:54] [Server Shutdown Thread/INFO]: Stopping server
[16:25:54] [Server Shutdown Thread/INFO]: Saving players
[16:25:54] [Server Shutdown Thread/INFO]: Saving worlds

As for the reboot intervals the op has a picture that gives a pretty good description of intervals. Which is approximately 60 seconds.

As for Misconfigured permissions, I would think that would be unlikely. I should see when I login to SFTP any discrepancies and everything is transferred as the MC user. But there has to be something that’s going wrong in its most likely user error I just can’t imagine what.

This also affects a vanilla server. Everything at that point is handled by the web interface.


#13

Well I think I found the source of our problem as seen with the vanilla server.

[14:30:25] [Server thread/INFO]: Starting minecraft server version 1.8.8
[14:30:25] [Server thread/WARN]: To start the server with more ram, launch it as "java -Xmx1024M -Xms1024M -jar minecraft_server.jar"
[14:30:25] [Server thread/INFO]: Loading properties
[14:30:25] [Server thread/INFO]: Default game type: SURVIVAL
[14:30:25] [Server thread/INFO]: Generating keypair
[14:30:25] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25564
[14:30:26] [Server thread/INFO]: Using epoll channel type
[14:30:26] [Server thread/INFO]: Preparing level "world"
[14:30:26] [Server thread/INFO]: Preparing start region for level 0
[14:30:26] [Server thread/INFO]: Done (0.809s)! For help, type "help" or "?"
[14:41:03] [Server console handler/ERROR]: Exception handling console input
java.io.IOException: Input/output error
    at java.io.FileInputStream.readBytes(Native Method) ~[?:1.8.0_66-internal]
    at java.io.FileInputStream.read(FileInputStream.java:255) ~[?:1.8.0_66-internal]
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:284) ~[?:1.8.0_66-internal]
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345) ~[?:1.8.0_66-internal]
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) ~[?:1.8.0_66-internal]
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) ~[?:1.8.0_66-internal]
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) ~[?:1.8.0_66-internal]
    at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[?:1.8.0_66-internal]
    at java.io.BufferedReader.fill(BufferedReader.java:161) ~[?:1.8.0_66-internal]
    at java.io.BufferedReader.readLine(BufferedReader.java:324) ~[?:1.8.0_66-internal]
    at java.io.BufferedReader.readLine(BufferedReader.java:389) ~[?:1.8.0_66-internal]
    at ko$2.run(SourceFile:81) [minecraft_server.1.8.8.jar:?]

This might be the real problem and it could be massed by Forge. This does not generate a crash report.


#14

Try updating to the latest commit c576847c5841b706d1c7054cc42f55025bd0a2af and see if this issue persists.

This was a suspicion I had–because I introduced a bug recently (that I didn’t think would have this effect)…
I added the “save-all” frequency to the webui, which sent the command saveall to the console. Of course, the correct command is save-all, so it was a typo. Despite that, the game … shouldn’t crash because it receives saveall–it would be literally like if you typed it into the console and then everything died (it should handle it more gracefully).

however, if you went back to the commit I told you earlier:

this previous commit I had you roll back to–didn’t have this functionality at all (and thus didn’t have the bug). Rolling back to the previous commit should have solved this issue (if going to the most recent commit, in fact, fixes anything).

But at least we have something to work with. Update to the most recent commit and try setting the value to (which disables this) and see if your servers stay up.


A funny thing happened on the way to my MineOS WebUI
#15

I updated to the latest commit. The results are both of the servers end up stopping. The modded server doesn’t reboot. I made sure the values were blank for Minutes between committing world to disk via 'save-all' (empty to disable). Although in the box it still says in a light gray color 60.

The logs are identical for Modded when compared vanilla.
[17:38:34] [Server thread/INFO]: Starting minecraft server version 1.8
[17:38:38] [Server thread/INFO]: Loading properties
[17:38:38] [Server thread/INFO]: Default game type: SURVIVAL
[17:38:38] [Server thread/INFO]: Generating keypair
[17:38:38] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
[17:38:40] [Server thread/INFO]: Preparing level “world”
[17:38:40] [Server thread/INFO]: Preparing start region for level 0
[17:38:41] [Server thread/INFO]: Done (1.145s)! For help, type “help” or “?”
[17:38:41] [Server thread/INFO]: Starting GS4 status listener
[17:38:41] [Query Listener #1/INFO]: Query running on 0.0.0.0:25565
[17:39:30] [Server console handler/ERROR]: Exception handling console input
java.io.IOException: Input/output error
at java.io.FileInputStream.readBytes(Native Method) ~[?:1.8.0_66-internal]
at java.io.FileInputStream.read(FileInputStream.java:255) ~[?:1.8.0_66-internal]
at java.io.BufferedInputStream.read1(BufferedInputStream.java:284) ~[?:1.8.0_66-internal]
at java.io.BufferedInputStream.read(BufferedInputStream.java:345) ~[?:1.8.0_66-internal]
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) ~[?:1.8.0_66-internal]
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) ~[?:1.8.0_66-internal]
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) ~[?:1.8.0_66-internal]
at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[?:1.8.0_66-internal]
at java.io.BufferedReader.fill(BufferedReader.java:161) ~[?:1.8.0_66-internal]
at java.io.BufferedReader.readLine(BufferedReader.java:324) ~[?:1.8.0_66-internal]
at java.io.BufferedReader.readLine(BufferedReader.java:389) ~[?:1.8.0_66-internal]
at net.minecraft.server.dedicated.DedicatedServer$2.run(DedicatedServer.java:97) [pq.class:?]
[17:39:30] [Server Shutdown Thread/INFO]: Stopping server
[17:39:30] [Server Shutdown Thread/INFO]: Saving players
[17:39:30] [Server Shutdown Thread/INFO]: Saving worlds
[17:39:30] [Server Shutdown Thread/INFO]: Saving chunks for level ‘world’/Overworld

If the commands you gave were complete I believe I did rollback the server as requested.

Edit: it seems all this is revolving around the act of writing to the disk file’s which causes the server to shut down. Maybe it’s not the command itself but the act of writing to disk. So that leads us back to permissions but also the possibility of hhd integrity? I’ll try running badblocks -nvs /dev/sdb1


Required nodejs version?
#16

Can you check to make sure that all the files in the server are properly owned by the user it should be? (presumably ben:mineos_admins)?

Especially the log files–if any are owned by a different user (such as root), these problems would crop up regularly. However, files don’t typically get chowned to root either, so, it’s worth looking at.


#17

Actually its mc:mc
Although I would like to when this is figured out ben:mineos_admins
As of right now neither ben or mineos_admins show up in the web UI.


#19

edit:Pass completed, 0 bad blocks found. (0/0/0 errors)


#20

Connect to your server with your mc user and connect specifically to your console with screen -r. Try typing in commands like saveall or save-all and see if you can replicate the crash.

The only substantial change in code I’ve made to MineOS recently that would be related to the input error you’re getting relates to this save-all, so also have you verified that the crashes continue even with save-all disabled (emptied out? – the gray placeholder text does not have any effect).


#22

save-all works as expected on both servers without causing them to stop.

I noticed something very interesting! While testing using screen -r/saveall I had the shell and browser open side by side. As I’ve previously mentioned I’ve had problems with the web UI becoming unresponsive forcing me to re-login.

During this round of testing I was refreshing the browser every few seconds. At the exact time shell reported [screen is terminating](which means the server shutdown) the web UI forced me to re-login. It’s consistent every time when relogging in both are shut down. So being forced to re-log in to the web UI in correlates with the servers
terminating.

That would explain the error message and why the mc servers are not being shut down gracefully.