MineOS Docker install on Synology box: can't start server, very little log output


#1

I ran MineOS as a plugin in FreeNAS for years (so many years, at this point, that I can barely remember setting it up… which might be contributing to my problems now).

I’m currently trying to get a MineOS install up and running on Synology box using Docker. I’ve used Docker successfully to set up other projects (like an Obooquity server) so I’m not a total potato, but I’m clearly enough of a potato that I’ve been completely foiled by this MineOS project. Here’s what I’ve done so far (I’ll include the log at the end):

  1. Created a Docker container using the Hexparrot docker build, found here: https://hub.docker.com/r/hexparrot/mineos/

  2. Used the Volume function in Docker to mount the following, (formatted as DockerLocation >>to>> SynologyLocation):

/var/log/mineos.log >>to>> /docker/mineoe/logs/mineos.log
/var/games/minecraft >>to>> /minecraft/mineos_servers
/config >>to>> /docker/mineos

  1. Set the following environmental variables:

PGID: 101
PUID: 1026
USER_PASSWORD: minecraft

  1. Initial Run:
  • Started the container and logged into the MineOS web interface.
  • Downloaded a copy of the 1.13.2 server.
  • Created a “Test_Server” with default settings.
  • Accepted EULA and attempted to run.
  • Server failed to run.
  1. Checked both /profiles/ and /servers/ folders. 1.13.2 server is present in both folders and the correct size.

Here is the log, after a fresh restart, from the point that the docker comes online to me logging in and attempting to start, via the GUI, the “Test_Server”. There’s not a whole lot in the log and trying to search for a solution based on the sparse log hasn’t yielded anything that has helped me at all. There’s more of the log file before the point I start it below, but it’s all identical to what’s below after the fresh restart.

—Begin Log—

{“level”:“info”,“message”:"[Test_Server] Discovered server",“timestamp”:“2019-02-10T21:47:32.613Z”}
{“level”:“error”,“message”:"[Test_Server] Create tail on logs/latest.log failed",“timestamp”:“2019-02-10T21:47:32.618Z”}
{“level”:“info”,“message”:"[Test_Server] Watching for file generation: logs/latest.log",“timestamp”:“2019-02-10T21:47:32.618Z”}
{“level”:“error”,“message”:"[Test_Server] Create tail on server.log failed",“timestamp”:“2019-02-10T21:47:32.658Z”}
{“level”:“info”,“message”:"[Test_Server] Watching for file generation: server.log",“timestamp”:“2019-02-10T21:47:32.658Z”}
{“level”:“error”,“message”:"[Test_Server] Create tail on proxy.log.0 failed",“timestamp”:“2019-02-10T21:47:32.659Z”}
{“level”:“info”,“message”:"[Test_Server] Watching for file generation: proxy.log.0",“timestamp”:“2019-02-10T21:47:32.659Z”}
{“level”:“error”,“message”:"[Test_Server] Create tail on logs/fml-server-latest.log failed",“timestamp”:“2019-02-10T21:47:32.660Z”}
{“level”:“info”,“message”:"[Test_Server] Watching for file generation: logs/fml-server-latest.log",“timestamp”:“2019-02-10T21:47:32.660Z”}
{“level”:“info”,“message”:"[Test_Server] Using skipDirEntryPatterns: world,world_the_end,world_nether,dynmap,plugins,web,region,playerdata,stats,data",“timestamp”:“2019-02-10T21:47:32.661Z”}
{“level”:“info”,“message”:“Starting up server, using commit: b28c5be fw.ignore for all skip_dirs\n”,“timestamp”:“2019-02-10T21:47:32.914Z”}
{“level”:“info”,“message”:"[Test_Server] eula.txt detected: ACCEPTED (eula=true)",“timestamp”:“2019-02-10T21:47:33.183Z”}
{“level”:“info”,“message”:"[Test_Server] autostart = false",“timestamp”:“2019-02-10T21:47:37.730Z”}
{“level”:“error”,“message”:"[Test_Server] Aborted server startup; condition not met: true",“timestamp”:“2019-02-10T21:47:37.731Z”}
{“level”:“info”,“message”:"[WEBUI] mc connected from 172.17.0.1",“timestamp”:“2019-02-10T21:52:06.114Z”}
{“0”:“de_DE”,“1”:“en_US”,“2”:“fr_FR”,“3”:“it_IT”,“4”:“ja_JP”,“5”:“no_NB”,“6”:“ru_RU”,“7”:“sv_SE”,“level”:“info”,“message”:"",“timestamp”:“2019-02-10T21:52:06.437Z”}
{“level”:“info”,“message”:"[Test_Server] mc (172.17.0.1) joined server namespace",“timestamp”:“2019-02-10T21:52:06.466Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Mojang Official Minecraft Jars (372 entries)”,“timestamp”:“2019-02-10T21:52:06.818Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Feed the Beast Third-Party Server Packs (314 entries)”,“timestamp”:“2019-02-10T21:52:07.968Z”}
{“level”:“info”,“message”:“Downloaded information for collection: PaperSpigot (5 entries)”,“timestamp”:“2019-02-10T21:52:07.988Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Spigot (1 entries)”,“timestamp”:“2019-02-10T21:52:07.994Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Imagicalmine (1 entries)”,“timestamp”:“2019-02-10T21:52:07.998Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Feed the Beast Server Packs (504 entries)”,“timestamp”:“2019-02-10T21:52:08.934Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Forge Mod (35 entries)”,“timestamp”:“2019-02-10T21:52:12.175Z”}
{“level”:“info”,“message”:“Downloaded information for collection: SpongeVanilla (820 entries)”,“timestamp”:“2019-02-10T21:52:12.721Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Mianite (23 entries)”,“timestamp”:“2019-02-10T21:52:12.740Z”}
{“level”:“info”,“message”:“Downloaded information for collection: BungeeCord (10 entries)”,“timestamp”:“2019-02-10T21:52:12.742Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Nukkit (2 entries)”,“timestamp”:“2019-02-10T21:52:12.742Z”}
{“level”:“info”,“message”:“Downloaded information for collection: Cuberite C++ Server (4 entries)”,“timestamp”:“2019-02-10T21:52:13.718Z”}
{“level”:“info”,“message”:"[Test_Server] 172.17.0.1 issued command : “modify_sc”",“timestamp”:“2019-02-10T21:52:17.210Z”}
{“level”:“info”,“message”:"[Test_Server] received request “modify_sc”",“timestamp”:“2019-02-10T21:52:17.214Z”}
{“level”:“info”,“message”:"[Test_Server] 172.17.0.1 issued command : “modify_sc”",“timestamp”:“2019-02-10T21:52:19.281Z”}
{“level”:“info”,“message”:"[Test_Server] received request “modify_sc”",“timestamp”:“2019-02-10T21:52:19.283Z”}
{“level”:“info”,“message”:"[Test_Server] 172.17.0.1 issued command : “start”",“timestamp”:“2019-02-10T21:52:20.704Z”}
{“level”:“info”,“message”:"[Test_Server] received request “start”",“timestamp”:“2019-02-10T21:52:20.705Z”}

—End Log—

It’s possible I’m overlooking something very basic as I’m not a power user of either Docker or MineOS. I’ll take any advice I can get and I’ll happily dig up any additional log files if you tell me where to look. Thanks for reading this far!


#2

Have you tried an older minecraft version? There may be a java-version error.


#3

Have you tried an older minecraft version? There may be a java-version error.

Good idea to explore. Unfortunately, I just tried it with MC ver. 1.7.10 and got an identical log output to what I got with the 1.13.2 server.


#4

Ok.
Try to SSH into your MineOS server and try to start the server manually. this should send out any java related errors that are unlogged


#5

I logged into the MineOS docker installed and manually launched the server. The following output is the result, the server appears stable other than complaining about lag/missed ticks:

—Begin Log—

[00:54:07] ain/WARN]: Ambiguity between arguments [teleport, destination] and [teleport, targets] with inputs: [Player, 0123, @e, XXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXXX]
[00:54:07] ain/WARN]: Ambiguity between arguments [teleport, location] and [teleport, destination] with inputs: [0.1 -0.5 .9, 0 0 0]
[00:54:07] ain/WARN]: Ambiguity between arguments [teleport, location] and [teleport, targets] with inputs: [0.1 -0.5 .9, 0 0 0]
[00:54:07] ain/WARN]: Ambiguity between arguments [teleport, targets] and [teleport, destination] with inputs: [Player, 0123, XXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXXX]
[00:54:07] ain/WARN]: Ambiguity between arguments [teleport, targets, location] and [teleport, targets, destination] with inputs: [0.1 -0.5 .9, 0 0 0]
[00:54:07] ain/INFO]: Loaded 0 recipes
[00:54:07] ain/INFO]: Loaded 0 advancements
[00:54:07] [Server thread/INFO]: Starting minecraft server version 1.13.2
[00:54:07] [Server thread/INFO]: Loading properties
[00:54:07] [Server thread/INFO]: Default game type: SURVIVAL
[00:54:07] [Server thread/INFO]: Generating keypair
[00:54:09] [Server thread/INFO]: Starting Minecraft server on 0.0.0.0:25565
[00:54:09] [Server thread/INFO]: Using epoll channel type
[00:54:09] [Server thread/INFO]: Preparing level “world”
[00:54:09] [Server thread/INFO]: Reloading ResourceManager: Default
[00:54:12] [Server thread/INFO]: Loaded 524 recipes
[00:54:15] [Server thread/INFO]: Loaded 571 advancements
[00:54:15] [Server thread/INFO]: Preparing start region for dimension minecraft:overworld
[00:54:16] [Server thread/INFO]: Preparing spawn area: 4%
[00:54:16] [Server thread/INFO]: Preparing spawn area: 8%
[00:54:16] [Server thread/INFO]: Preparing spawn area: 12%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 16%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 20%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 24%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 28%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 32%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 36%
[00:54:17] [Server thread/INFO]: Preparing spawn area: 40%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 44%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 48%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 52%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 56%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 60%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 64%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 68%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 72%
[00:54:18] [Server thread/INFO]: Preparing spawn area: 76%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 80%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 84%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 88%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 92%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 96%
[00:54:19] [Server thread/INFO]: Preparing spawn area: 100%
[00:54:19] [Server thread/INFO]: Time elapsed: 3663 ms
[00:54:19] [Server thread/INFO]: Done (9.672s)! For help, type “help”
[00:54:20] [Server thread/INFO]: Unknown command
[00:54:20] [Server thread/INFO]: <–[HERE]
[00:54:21] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 2017ms or 40 ticks behind
[00:56:31] [User Authenticator #1/INFO]: UUID of player PLAYERNAME is XXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXXX
[00:56:31] [Server thread/INFO]: PLAYERNAME[/172.17.0.1:40351] logged in with entity id 196 at (-246.5, 69.0, -48.5)
[00:56:31] [Server thread/INFO]: PLAYERNAME joined the game
[00:57:10] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 7023ms or 140 ticks behind
[00:57:10] [Server thread/WARN]: PLAYERNAME moved too quickly! -6.580246036103688,-3.3331999936342243,7.117133277060881
[00:57:45] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 2026ms or 40 ticks behind
[00:58:03] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 3373ms or 67 ticks behind
[00:58:22] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 3278ms or 65 ticks behind
[00:58:22] [Server thread/WARN]: PLAYERNAME moved too quickly! 9.105783454684264,-2.0,3.7154644553696663
[00:58:43] [Server thread/WARN]: Can’t keep up! Is the server overloaded? Running 6581ms or 131 ticks behind

—End Log—

I ran around for a few hundred blocks, died, respawned, ran around some more. Maybe a tiny bit of lag but otherwise the experience was as expected.

Curiously, when I loaded up the MineOS GUI while this was going on the GUI indicated the server was not running (marked as “Down”) but the logging tab at the very botton of the left hand navigation panel was active and I could watch the log of the running server in real time. Not sure what to make of that. Attempting to stop, start, or restart the server via the GUI has zero effect (and no effects are seen in the server log, which remains running).

Is the issue that whatever user the GUI is running at doesn’t have the proper permissions? And, if so, how do I go about checking for that?


#6

MineOS cannot manage manually-launched servers. Or at least, it cannot manage any servers that are not contained within a screen instance that follows the pattern “mc-[servername]”.

Since you launched it without screen, it’s invisible to MineOS.

So it’s a bit of a misnomer to say that it is down, but as far as the webui is concerned, it’s fairly accurate. Of course, if you tried running it also from the webui, then you’d just get the error saying it’s trying to run two servers on the same port.

That said, I have no idea what synology is, but FreeNAS has a long-standing issue of the Java version causing issues (often the JDK isn’t up to date, etc.).

Since you’ve provided the logs, we can see that MineOS has gone as far as accepting the ‘start’ command, so the best way to trace it is:

  1. create a new server
  2. go through all the steps up to ‘start’
  3. Attempt to start it.
  4. Go to the server’s file directory:
  • is the eula present, and do the contents say it is accepted? (checking that that part worked)
  • did it generate logs, e.g., logs/latest.log

If there are no logs generated, the webui is likely having a Java issue.

But this time, it might be that the environmental variables for the user cannot find Java, which is different from the exact same user being able to run it manually (because interactive login prompts source variables that won’t happen in non-login prompts). This is actually only my second guess, while my best guess is:

The issue might be something related to the GID/UID ownership of the files. I don’t do much with containerization, but it’s very possible this is related, since

This might indicate that MineOS definitely sees these files get created, but cannot access them, as the webui’s user UID/GID may not actually match the ownership of the files on the containerized FS.


#7

Thanks for the reply!

I created a new server named HP_Test and went through the startup process. The server failed to launch but the eula.txt was updated to “true”. The created server directory only contains the following files:

cron.config
eula.txt
minecraft_server.1.13.2.jar
server.config
server.properties

There are no additional files or directories.

This might indicate that MineOS definitely sees these files get created, but cannot access them, as the webui’s user UID/GID may not actually match the ownership of the files on the containerized FS.

How can I go about checking if this is the case?


#9

Let’s try starting up the server with MineOS via command-line:

Do this as root:

cd /usr/games/minecraft
./mineos_console.js -d /var/games/minecraft -s HP_Test start

#10

It appears to simply echo the solitary “start” command we see in the earlier log. Here’s the command and output:

root@hexparrot-mineos1:/etc# cd /usr/games/minecraft
root@hexparrot-mineos1:/usr/games/minecraft# ./mineos_console.js -d /var/games/minecraft -s HP_Test start
[HP_Test] Successfully executed “start”

Nothing follows after that and does not appear the server is running (and there are no changes to the /servers/HP_Test/ directory).


#11

ls -n /var/games/minecraft/servers/HP_Test

What are the uid/gids produced here?


#12

Here’s the command output, looks like everything is 1000/1000 which matches the “mc” server/group owner in the MineOS interface.

root@hexparrot-mineos1:/# ls -n /var/games/minecraft/servers/HP_Test
total 33056
-rwxrwx— 1 1000 1000 0 Feb 11 19:39 cron.config
-rwxrwx— 1 1000 1000 9 Feb 11 19:40 eula.txt
-rw-rw---- 1 1000 1000 33835116 Feb 10 20:08 minecraft_server.1.13.2.jar
-rwxrwx— 1 1000 1000 108 Feb 11 19:40 server.config
-rwxrwx— 1 1000 1000 208 Feb 11 19:39 server.properties


#13

Again, my familiarity with Synology is nil, so can you let me know what these GID/UIDs are meant for?


#14

No problem. Even though I use Synology as a NAS (it’s both a hardware and software company that produces NAS hardware and a pretty consumer-friendly operating system to run on the NAS hardware) a lot of what I’m doing using Docker on it is just based on information cobbled together from tutorials. I’ll do my best to explain though.

When you set up a lot of Docker containers on Synology you’re instructed to supply the PGID and PUID of the admin user of the Synology OS the Docker install is on. The default is 101/1026 (which I confirmed with the “id” command when logged into the terminal on the Synology box). I think this is so you can access the volumes on the Synology for data storage outside the Docker container (like keeping the Minecraft servers in /minecraft/mineOS/ on the main storage volume).


#15

It’s pretty hard to troubleshoot this. I’m unfamiliar with what synology might otherwise be doing with docker that keeps it locked down, e.g., AppArmors or SELinux, or any other nuances that make this different from a normal docker installation.

That said, let’s give this a try. As root, and from within the mineos container:

# which node
# cd /usr/games/minecraft
# node
> var which = require('which')
> which('java', function(a,b) { bin_java = b })
> which('screen', function(a,b) { bin_screen = b })
> var child_process = require('child_process')
> var proc = child_process.spawn(bin_screen, ['-dmS', 'mc-HP_Test', bin_java, '-jar', '/var/games/minecraft/servers/HP_Test/minecraft_server.1.11.jar', 'nogui'], { uid: 1000, gid: 1000, stdio: 'inherit' })
> proc.pid

Copy paste the entire session including the typed commands and their response.

You should see, also, in top that the screen and java processes are running, probably 1 or 2 numbers higher than the proc.pid

You can at this point log into your mc user (or whoever 1000:1000 is) and connect to the screen:

screen -r 

This will show you the error that Java is producing. I’m going to guess it’s going to be erroring out at “Generating new properties file” because that’s the first time Minecraft tries to make a filechange that would be noticeable with ls (updated timestamp).

Of course, all this gives us a little more information, but not much more actionable information because if what’s occurring is exactly as I describe it, it still doesn’t give me a good idea about why it can’t…

One thing to take note of here, is that this is 100% node code and none of it has anything to do with MineOS. This is, however, exactly what MineOS is doing in the back-end. When these steps can be made to work, I’m assured MineOS (the webui) will work exactly as expected, too.


EDIT:
I just did some googling and found this.

Unless I’m misreading, Synology is somehow restricting the docker to a subset of features compared to other, vanilla docker installs.

The thread goes on to say that a user cannot even start a container with --security-opt apparmor:unconfined, which is to say that AppArmor is potentially on, but the user cannot change the security zone with arbitrary commands.

It might be possible, then, to let this work by turning on the “Execute container using high privilege” option in SyncologyUI, but I suspect there are security ramifications to that, and you’ll have to decide for yourself if that’s an OK thing.


#16

I really appreciate all your help trying to get to the bottom of this. I’ve got a couple things to report.

First, I tried out the commands as you requested, logged into the MineOS docker as root. I’m not sure if I did it wrong or if there is something about the Docker install that is preventing the commands from executing, but here’s the log:

root@hexparrot-mineos1:/# which node
/usr/bin/node
root@hexparrot-mineos1:/# cd /usr/games/minecraft
root@hexparrot-mineos1:/usr/games/minecraft# node
var which = require(‘which’)
undefined
which(‘screen’, function(a,b) { bin_screen = b })
undefined
var child_process = require(‘child_process’)
undefined
var proc = child_process.spawn(bin_screen, [’-dmS’, ‘mc-HP_Test’, bin_java, ‘-jar’, ‘/var/games/minecraft/servers/HP_Test/minecraft_server.1.11.jar’, ‘nogui’], { uid: 1000, gid: 1000, stdio: ‘inherit’ })
ReferenceError: bin_java is not defined
proc.pid
TypeError: Cannot read property ‘pid’ of undefined

After my poor luck working in the original MineOS docker, I created a new MineOS docker using the same image to test your theory about the “Execute container using high privilege” toggle. I turned that on for the second MineOS instance and MineOS functions completely as you would expect it. I was able to create a new profile for a 1.13.2 server, create a new server, run the server, and log into it. The server is still, hiccup free, running.

Clearly the high privilege toggle did something, although I don’t know specifically what. For my particular application I’m not super worried about increasing the privileges of the Docker container because the container is on a small NAS that is completely behind a firewall with no exposed ports (and used only for fun projects like this and local file backup).

I wish I had the technical know how to dig into this deeper and present a functional solution for anyone else running into the same issue I’m running into but who doesn’t want to toggle on the high privilege toggle for whatever reason. Forum posts have good solutions have saved me so many times over the years so I’m going to leave this open ended: if anybody comes along, finds this thread, and has any sort of idea how this Docker install could be fixed without using the high privilege toggles–I’m going to stay subscribed to this thread and will try out any solutions people propose to see if I can fix it.


#18

Glad to see it works. I think that means that for all intents and purposes, this can be considered SOLVED, because unless Synology reports some drastic security model changes where one can submit arbitrary parameters to the docker creation, I think “high privilege” is going to be a necessity on that particular platform and their security model.


Side note, regarding your attempt at node (which you no longer need to do since we found out the cause):

Did you miss this line?


#19

It would appear, indeed, that I missed that line because when I entered the commands again I got an output for the proc command which I didn’t before:

suroot@hexparrot-mineos1:/# which node
/usr/bin/node
root@hexparrot-mineos1:/# cd /usr/games/minecraft
root@hexparrot-mineos1:/usr/games/minecraft# node
var which = require(‘which’)
undefined
which(‘java’, function(a,b) { bin_java = b })
undefined
which(‘screen’, function(a,b) { bin_screen = b })
undefined
var child_process = require(‘child_process’)
undefined
var proc = child_process.spawn(bin_screen, [’-dmS’, ‘mc-HP_Test’, bin_java, ‘-jar’, ‘/var/games/minecraft/servers/HP_Test/minecraft_server.1.13.2.jar’, ‘nogui’], { uid: 1000, gid: 1000, stdio: ‘inherit’ })
undefined
proc.pid
44

The weird thing, and maybe I’m just not understanding how this Docker container is set up, is that none of the commands I would expect to work in a Linux virtualization are working. Commands like top, for example, are apparently missing.

root@hexparrot-mineos1:/usr/games/minecraft# top
bash: top: command not found

I have a feeling this might have something to do with how I got into the Docker itself though. By default there’s no direct SSH, as I understand it, so I jumped into the shell for the docker using the following command:

sudo docker exec -t -i hexparrot-mineos1 /bin/bash

This is probably less than ideal and if I’m going to keep troubleshooting things I should probably figure out how to SSH directly into the Docker?

At any rate, I do agree with you that for practical purposes the problem presented in this thread is solved (thanks to you!), but I’ll still keep an eye on the thread if anybody has any questions or wants me to test something out.