Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DietPi-Sotware | PaperMC #4039

Merged
merged 9 commits into from
Feb 2, 2021
Merged

DietPi-Sotware | PaperMC #4039

merged 9 commits into from
Feb 2, 2021

Conversation

Joulinar
Copy link
Collaborator

@Joulinar Joulinar commented Jan 5, 2021

Status: Done

  • update dietpi-software
  • installation testing

Reference: https://dietpi.com/phpbb/viewtopic.php?p=30191#p30191

It is needed to update download URL according PaperMC docs
https://paper.readthedocs.io/en/latest/site/api.html#i-just-want-to-download-the-latest-jar

As well timer to start service would need to be increased as config file creation needs longer than 25 sec
[ INFO ] DietPi-Software | PaperMC config file got created after 61 seconds

Commit list/description:

  • DietPi-Software | PaperMC: change download url and increase timer to create initial config files
  • DietPi-Software | PaperMC: reduce max java memory setting from 1024m down to 512m
  • DietPi-Software | PaperMC: ensure a memory setting of min 2GB (phys + swap). If needed, create a swap file
  • DietPi-Software | PaperMC: show an information about long start time during initial config creation
  • DietPi-Software | PaperMC : added new download URL to obtain latest PaperMC version
  • DietPi-Software | PaperMC : added an information about initial java memory settings and a reference to DietPi Docs on how to adjust them

@Joulinar Joulinar changed the title DietPi. DietPi-Sotware | PaperMC Jan 5, 2021
@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 5, 2021

@MichaIng
current PR contains a debug section because for me initial papermc.service start is failing after 60 sec with java.lang.OutOfMemoryError: Java heap space

Jan 05 01:19:56 DietPi3 systemd[1]: Started papermc (DietPi).
Jan 05 01:19:57 DietPi3 papermc[14053]: Downloading vanilla jar...
Jan 05 01:20:16 DietPi3 papermc[14053]: Patching vanilla jar...
Jan 05 01:20:55 DietPi3 papermc[14053]: Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
Jan 05 01:20:55 DietPi3 papermc[14053]:         at java.base/java.util.Arrays.copyOf(Arrays.java:3745)

therefore service would need to be restarted twice. Otherwise config files will not be created and following G_CONFIG_INJECT is failing.
[FAILED] DietPi-Software | Waiting for PaperMC config file timed out, skipping pre-configuration

Another "issue" is the new download url https://papermc.io/api/v1/paper/1.16.4/latest/download
This will lead to following install

[  OK  ] DietPi-Software | Checking URL: https://papermc.io/api/v1/paper/1.16.4/latest/download
[  OK  ] DietPi-Software | cd /tmp/DietPi-Software
[  OK  ] DietPi-Software | curl -sSfL https://papermc.io/api/v1/paper/1.16.4/latest/download -o download
[  OK  ] DietPi-Software | Verifying download target: /opt/papermc/paperclip.jar
[  OK  ] DietPi-Software | mkdir -p /opt/papermc
[  OK  ] DietPi-Software | mv download /opt/papermc/paperclip.jar

as you can see, file will be stored as -o download by curl

@Joulinar Joulinar requested a review from MichaIng January 5, 2021 00:36
@Joulinar Joulinar self-assigned this Jan 5, 2021
@Joulinar Joulinar added this to the v6.35 milestone Jan 5, 2021
@MichaIng
Copy link
Owner

MichaIng commented Jan 5, 2021

java.lang.OutOfMemoryError: Java heap space

This means we need to grant it more memory, e.g. java -Xmx1024m
Probably the long first startup times (with Geyser and Floodgate) are due to insufficient memory as well, never thought about that. Let's first play with that max memory before we implement some unreliable workaround with restarts and long timeouts (which might need to be much longer on things like RPi Zero). If that requires raising swap size, be it so.

as you can see, file will be stored as -o download by curl

That is not an issue, the file is moved to correct location and name after download. It's simply that curl does not automatically change the filename based on some response headers but uses the last path element only. Hmm, actually I'm wondering why I didn't use the "target" filename for the download, if present, which wouldn't look that strange in such cases 🤔.

But what I like about the new download URL is that it matches the Nukkit sources and allows to skip the patch version (latest 1.16 instead of 1.16.4). Strange, when I enter that URL in browser, it forcefully redirects me to GitHub authentication 😄.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 5, 2021

Strange, when I enter that URL in browser, it forcefully redirects me to GitHub authentication

Yes that's the old URL. The new one will download the jar file

@MichaIng
Copy link
Owner

MichaIng commented Jan 5, 2021

I mixed up old and new 😄.

Hmm, the links from the download page actually point to API v2, so the docs seem outdated.

Here is the latest download link from the main page: https://papermc.io/api/v2/projects/paper/versions/1.16.4/builds/390/downloads/paper-1.16.4-390.jar
What we could do is:

  1. Get latest version string from: https://papermc.io/api/v2/projects/paper
  2. Get latest build number from: https://papermc.io/api/v2/projects/paper/versions/1.16.4
  3. Forge download URL: https://papermc.io/api/v2/projects/paper/versions/$version/builds/$build/downloads/paper-$version-$build.jar

PaperMC/PaperDocs#47

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 5, 2021

well If I use https://papermc.io/api/v1/paper/1.16.4/latest/download I'm getting the latest file

image

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 5, 2021

using java -Xmx1024m seems to be working on my test system RPi3B+. Will add it to the service file. However first start is taking 2 minutes (without Geyser and Floodgate). Probably I will test on a RP1 later this evening.

 DietPi-Software
─────────────────────────────────────────────────────
 Mode: Configuring PaperMC: Highly optimised Minecraft server with plugins, written in Java

[  OK  ] DietPi-Software | Verifying user "papermc" to run PaperMC
[  OK  ] DietPi-Software | useradd -rMU -d /mnt/dietpi_userdata/papermc -s /usr/sbin/nologin papermc
[  OK  ] DietPi-Software | Checking URL: https://github.com/Tiiffi/mcrcon/archive/master.tar.gz
[  OK  ] DietPi-Software | cd /tmp/DietPi-Software
[  OK  ] DietPi-Software | curl -sSfL https://github.com/Tiiffi/mcrcon/archive/master.tar.gz -o master.tar.gz
[  OK  ] DietPi-Software | tar xf master.tar.gz
[  OK  ] DietPi-Software | rm master.tar.gz
[  OK  ] DietPi-Software | gcc -g0 -O3 mcrcon-master/mcrcon.c -o /usr/local/bin/mcrcon
[  OK  ] DietPi-Software | rm -R mcrcon-master
[  OK  ] DietPi-Software | strip --remove-section=.comment --remove-section=.note /usr/local/bin/mcrcon
[  OK  ] DietPi-Software | mkdir -p /var/log/papermc
[  OK  ] DietPi-Software | rm -Rf /mnt/dietpi_userdata/papermc/logs
[  OK  ] DietPi-Software | ln -s /var/log/papermc /mnt/dietpi_userdata/papermc/logs
[  OK  ] DietPi-Software | chown -R papermc:papermc /mnt/dietpi_userdata/papermc /var/log/papermc
[  OK  ] DietPi-Software | systemctl daemon-reload
[  OK  ] DietPi-Software | Starting PaperMC to pre-create config file
[  OK  ] DietPi-Software | systemctl stop papermc
[ INFO ] DietPi-Software | PaperMC config file got created after 118 seconds
[  OK  ] DietPi-Software | Setting in /mnt/dietpi_userdata/papermc/server.properties adjusted: enable-rcon=true
[  OK  ] DietPi-Software | Setting in /mnt/dietpi_userdata/papermc/server.properties adjusted: rcon.password=********
[  OK  ] DietPi-Autostart | systemctl daemon-reload
[ SUB1 ] DietPi-Services > dietpi_controlled
[  OK  ] DietPi-Services | dietpi_controlled : papermc
[  OK  ] DietPi-Services | dietpi_controlled : cron
[ SUB1 ] DietPi-Set_hardware > headless (disable)
[  OK  ] DietPi-Set_hardware | Desired setting in /boot/dietpi.txt was already set: AUTO_SETUP_HEADLESS=0
[  OK  ] headless disable | Completed
[  OK  ] DietPi-Survey | Purging survey data

 DietPi-Software
─────────────────────────────────────────────────────
 Mode: Installation completed

DietPi-Software | PaperMC: add memory parameter to the service to allow successful initial start of the service.
@MichaIng
Copy link
Owner

MichaIng commented Jan 5, 2021

The latest build, but not the latest version. Okay got reply and indeed API v1 is deprecated, hence we'd need to use v2: https://papermc.io/api/docs

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 5, 2021

So we would need to do following

to get version https://papermc.io/api/v2/projects/paper/
{"project_id":"paper","project_name":"Paper","version_groups":["1.8","1.9","1.10","1.11","1.12","1.13","1.14","1.15","1.16"],"versions":["1.8.8","1.9.4","1.10.2","1.11.2","1.12","1.12.1","1.12.2","1.13-pre7","1.13","1.13.1","1.13.2","1.14","1.14.1","1.14.2","1.14.3","1.14.4","1.15","1.15.1","1.15.2","1.16.1","1.16.2","1.16.3","1.16.4"]}

to get build based on version https://papermc.io/api/v2/projects/paper/versions/1.16.4
{"project_id":"paper","project_name":"Paper","version":"1.16.4","builds":[256,257,258,259,260,261,262,263,264,265,266,267,268,269,270,271,272,273,274,275,276,277,278,279,280,281,282,283,284,285,286,287,288,291,293,294,295,296,297,298,299,300,301,302,303,304,305,306,307,308,309,310,311,312,313,314,315,316,317,318,319,320,321,322,323,324,325,327,328,329,330,331,332,333,334,335,336,337,338,339,340,341,342,343,344,345,346,347,348,349,350,351,352,353,354,355,356,357,358,359,360,361,362,363,364,365,366,367,368,369,370,371,372,373,374,375,376,377,378,379,380,381,382,383,384,385,386,387,388,389,390]}

and get the file name
{"project_id":"paper","project_name":"Paper","version":"1.16.4","build":390,"time":"2021-01-05T11:26:12.365Z","changes":[{"commit":"66d3e622819d85f29e865f5b8ea66c064f5ffe50","summary":"Print name of busted server config files","message":"Print name of busted server config files\n"},{"commit":"05af2837cd508bf36dda470aecd08249b1fdfea0","summary":"[CI-SKIP] Improved the annotation test output","message":"[CI-SKIP] Improved the annotation test output\n"}],"downloads":{"application":{"name":"paper-1.16.4-390.jar","sha256":"4b70dd55c2a34158f1b47148b45d7d76a4cf0a3cfc0662addbedc9a3a14489c9"}}}

And finally have a download URL https://papermc.io/api/v2/projects/paper/versions/1.16.4/builds/390/downloads/paper-1.16.4-390.jar

EDIT: Ahh that's what you wrote above already

dietpi/dietpi-software Outdated Show resolved Hide resolved
@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 6, 2021

Installation on RPi1 is working as well. But honestly it is taking ages for the service to start. Not sure if it really make sense to have it running on boards with such less memory as the system is swapping already during initial start. PaperMC config file got created in around 10 minutes.
[ INFO ] DietPi-Software | PaperMC config file got created after 571 seconds

Maybe we should set timeout value depending on SBC? Or disable it for boards with less than 1GB phys memory.

@MichaIng
Copy link
Owner

MichaIng commented Jan 6, 2021

Would be interesting to see what it actually does that is taking so long, probably we can report it upstream, or we can request a change so that the config file is created earlier or even have an "init" command option to only create config file and directory structure and exiting automatically afterwards.
I'm wondering what has changed between the initial implementation, where AFAIK 20 seconds default limit (has been raised with last update) was enough to have PaperMC config file (without Spigot) and 256 MiB default max heap size (on 1 GiB physical memory system) and now so that memory usage has increased significantly and startup time by orders of magnitude 🤔.

Another thing, probably -Xmx512m would be sufficient to avoid the OOM error and probably it does not swap that much then, hence loads faster. I'm not sure how exactly Java handles this, but my impression was that it often consumes simply all of that memory (even that it is a max value, while there is a min and a start value as well) directly, even taking a while to fill it (especially for swap space of course), and when using a lower value it consumes of course less memory but without making me recognising any performance impact or other issues. Java does not know about swap, but to me the automatic memory handling always looked very inefficient, compared to how other runtime environments do it.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 6, 2021

that's the log for the first inital start on my RPi1. Most of time is spend on Downloading + Patching for vanilla jar as well as on Loading libraries

root@DietPi1:~# journalctl -u papermc
-- Logs begin at Mon 2020-12-28 20:32:58 CET, end at Wed 2021-01-06 19:01:24 CET. --
Jan 06 13:40:10 DietPi1 systemd[1]: Started papermc (DietPi).
Jan 06 13:40:12 DietPi1 papermc[3515]: Downloading vanilla jar...
Jan 06 13:41:48 DietPi1 papermc[3515]: Patching vanilla jar...
Jan 06 13:44:37 DietPi1 papermc[3515]: System Info: Java 1.8 (OpenJDK Client VM 25.212-b01) Host: Linux 5.4.79+ (arm)
Jan 06 13:44:37 DietPi1 papermc[3515]: Loading libraries, please wait...
Jan 06 13:48:53 DietPi1 papermc[3515]: [13:48:53 ERROR]: Failed to load properties from file: server.properties
Jan 06 13:48:57 DietPi1 papermc[3515]: [13:48:57 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', se
ssionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
Jan 06 13:49:02 DietPi1 papermc[3515]: [13:49:02 INFO]: Found new data pack file/bukkit, loading it automatically
Jan 06 13:49:20 DietPi1 papermc[3515]: [13:49:20 INFO]: Reloading ResourceManager: Default, bukkit
Jan 06 13:49:51 DietPi1 papermc[3515]: [13:49:51 INFO]: Loaded 7 recipes
Jan 06 13:51:12 DietPi1 papermc[3515]: [13:51:12 INFO]: Starting minecraft server version 1.16.4
Jan 06 13:51:13 DietPi1 papermc[3515]: [13:51:12 INFO]: Loading properties
Jan 06 13:51:17 DietPi1 papermc[3515]: [13:51:17 INFO]: This server is running Paper version git-Paper-391 (MC: 1.16.4) (Implementing API version 1.16.4
-R0.1-SNAPSHOT)
Jan 06 13:51:17 DietPi1 papermc[3515]: [13:51:17 INFO]: Console input is disabled due to --noconsole command argument
Jan 06 13:51:19 DietPi1 papermc[3515]: [13:51:19 INFO]: Using 4 threads for Netty based IO
Jan 06 13:51:19 DietPi1 papermc[3515]: [13:51:19 INFO]: Server Ping Player Sample Count: 12
Jan 06 13:51:19 DietPi1 papermc[3515]: [13:51:19 INFO]: Debug logging is disabled
Jan 06 13:51:21 DietPi1 papermc[3515]: [13:51:21 INFO]: Default game type: SURVIVAL
Jan 06 13:51:21 DietPi1 papermc[3515]: [13:51:21 INFO]: Generating keypair
Jan 06 13:51:27 DietPi1 papermc[3515]: [13:51:27 INFO]: Starting Minecraft server on *:25565
Jan 06 13:51:28 DietPi1 papermc[3515]: [13:51:28 INFO]: Using default channel type
Jan 06 13:51:35 DietPi1 papermc[3515]: [13:51:35 INFO]: Preparing level "world"
Jan 06 13:51:40 DietPi1 systemd[1]: Stopping papermc (DietPi)...

Still I don't think running it on such small boards make sense. My RPi1 is running on 100% since I started at 1:30pm

image

as well systems seems not healthy according logs. But not sure if that's important

Jan 06 18:52:20 DietPi1 papermc[10960]: [18:52:20 WARN]: Can't keep up! Is the server overloaded? Running 59587ms or 1191 ticks behind
Jan 06 18:53:53 DietPi1 papermc[10960]: [18:53:53 WARN]: Can't keep up! Is the server overloaded? Running 63328ms or 1266 ticks behind
Jan 06 18:55:14 DietPi1 papermc[10960]: [18:55:14 WARN]: Can't keep up! Is the server overloaded? Running 50946ms or 1018 ticks behind
Jan 06 18:56:32 DietPi1 papermc[10960]: [18:56:32 WARN]: Can't keep up! Is the server overloaded? Running 48497ms or 969 ticks behind
Jan 06 18:58:12 DietPi1 papermc[10960]: [18:58:12 WARN]: Can't keep up! Is the server overloaded? Running 69981ms or 1399 ticks behind
Jan 06 18:59:42 DietPi1 papermc[10960]: [18:59:42 WARN]: Can't keep up! Is the server overloaded? Running 59928ms or 1198 ticks behind
Jan 06 19:01:24 DietPi1 papermc[10960]: [19:01:23 WARN]: Can't keep up! Is the server overloaded? Running 71299ms or 1425 ticks behind
Jan 06 19:02:47 DietPi1 papermc[10960]: [19:02:47 WARN]: Can't keep up! Is the server overloaded? Running 53787ms or 1075 ticks behind
Jan 06 19:04:20 DietPi1 papermc[10960]: [19:04:20 WARN]: Can't keep up! Is the server overloaded? Running 62525ms or 1250 ticks behind
Jan 06 19:05:47 DietPi1 papermc[10960]: [19:05:47 WARN]: Can't keep up! Is the server overloaded? Running 57541ms or 1150 ticks behind

Will test -Xmx512m on my RPi3B+ later the evening

@MichaIng
Copy link
Owner

MichaIng commented Jan 6, 2021

Jan 06 18:01:03 VM-Buster systemd[1]: Started papermc (DietPi).
Jan 06 18:01:03 VM-Buster papermc[4891]: Downloading vanilla jar...
Jan 06 18:01:14 VM-Buster papermc[4891]: Patching vanilla jar...
Jan 06 18:01:30 VM-Buster systemd[1]: Stopping papermc (DietPi)...
Jan 06 18:01:32 VM-Buster systemd[1]: papermc.service: Main process exited, code=exited, status=143/n/a
Jan 06 18:01:32 VM-Buster systemd[1]: papermc.service: Failed with result 'exit-code'.
Jan 06 18:01:32 VM-Buster systemd[1]: Stopped papermc (DietPi).
Jan 06 18:01:47 VM-Buster systemd[1]: Started papermc (DietPi).
Jan 06 18:01:49 VM-Buster papermc[5382]: System Info: Java 11 (OpenJDK 64-Bit Server VM 11.0.9.1+1-post-Debian-1deb10u2) Host: Linux 4.19.0-13-amd64 (amd64)
Jan 06 18:01:49 VM-Buster papermc[5382]: Loading libraries, please wait...
Jan 06 18:02:06 VM-Buster papermc[5382]: [18:02:06 ERROR]: Failed to load properties from file: server.properties
Jan 06 18:02:06 VM-Buster papermc[5382]: [18:02:06 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
Jan 06 18:02:07 VM-Buster papermc[5382]: [18:02:07 INFO]: Found new data pack file/bukkit, loading it automatically
Jan 06 18:02:08 VM-Buster papermc[5382]: [18:02:08 INFO]: Reloading ResourceManager: Default, bukkit
Jan 06 18:02:10 VM-Buster papermc[5382]: [18:02:10 INFO]: Loaded 7 recipes
Jan 06 18:02:16 VM-Buster papermc[5382]: [18:02:16 INFO]: Starting minecraft server version 1.16.4
Jan 06 18:02:16 VM-Buster papermc[5382]: [18:02:16 WARN]: To start the server with more ram, launch it as "java -Xmx1024M -Xms1024M -jar minecraft_server.jar"
Jan 06 18:02:16 VM-Buster papermc[5382]: [18:02:16 INFO]: Loading properties
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: This server is running Paper version git-Paper-392 (MC: 1.16.4) (Implementing API version 1.16.4-R0.1-SNAPSHOT)
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Console input is disabled due to --noconsole command argument
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Debug logging is disabled
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Server Ping Player Sample Count: 12
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Using 4 threads for Netty based IO
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Default game type: SURVIVAL
Jan 06 18:02:17 VM-Buster papermc[5382]: [18:02:17 INFO]: Generating keypair
Jan 06 18:02:18 VM-Buster papermc[5382]: [18:02:18 INFO]: Starting Minecraft server on *:25565
Jan 06 18:02:18 VM-Buster papermc[5382]: [18:02:18 INFO]: Using epoll channel type
Jan 06 18:02:18 VM-Buster papermc[5382]: [18:02:18 INFO]: Preparing level "world"
Jan 06 18:02:34 VM-Buster papermc[5382]: [18:02:34 WARN]: Unable to find spawn biome
Jan 06 18:02:39 VM-Buster papermc[5382]: [18:02:39 WARN]: Unable to find spawn biome
Jan 06 18:02:43 VM-Buster papermc[5382]: [18:02:43 INFO]: Preparing start region for dimension minecraft:overworld
Jan 06 18:02:44 VM-Buster papermc[5382]: [18:02:44 INFO]: Loaded 0 spawn chunks for world world
Jan 06 18:02:44 VM-Buster papermc[5382]: [18:02:44 INFO]: Preparing spawn area: 0%
Jan 06 18:02:44 VM-Buster papermc[5382]: [18:02:44 INFO]: Preparing spawn area: 0%
Jan 06 18:02:45 VM-Buster papermc[5382]: [18:02:45 INFO]: Preparing spawn area: 0%
Jan 06 18:02:45 VM-Buster papermc[5382]: [18:02:45 INFO]: Time elapsed: 2645 ms
Jan 06 18:02:45 VM-Buster papermc[5382]: [18:02:45 INFO]: Preparing start region for dimension minecraft:the_nether
Jan 06 18:02:46 VM-Buster papermc[5382]: [18:02:46 INFO]: Loaded 0 spawn chunks for world world_nether
Jan 06 18:02:46 VM-Buster papermc[5382]: [18:02:46 INFO]: Preparing spawn area: 0%
Jan 06 18:02:46 VM-Buster papermc[5382]: [18:02:46 INFO]: Preparing spawn area: 0%
Jan 06 18:02:46 VM-Buster papermc[5382]: [18:02:46 INFO]: Time elapsed: 837 ms
Jan 06 18:02:46 VM-Buster papermc[5382]: [18:02:46 INFO]: Preparing start region for dimension minecraft:the_end
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Loaded 0 spawn chunks for world world_the_end
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Preparing spawn area: 0%
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Preparing spawn area: 0%
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Preparing spawn area: 0%
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Preparing spawn area: 0%
Jan 06 18:02:48 VM-Buster papermc[5382]: [18:02:48 INFO]: Preparing spawn area: 0%
Jan 06 18:02:50 VM-Buster papermc[5382]: [18:02:50 INFO]: Time elapsed: 3845 ms
Jan 06 18:02:50 VM-Buster papermc[5382]: [18:02:50 INFO]: Running delayed init tasks
Jan 06 18:02:50 VM-Buster papermc[5382]: [18:02:50 INFO]: Done (33.874s)! For help, type "help"
Jan 06 18:02:50 VM-Buster papermc[5382]: [18:02:50 INFO]: Timings Reset
2021-01-06 18:11:35 root@VM-Buster:/mnt/dietpi_userdata/papermc# l cache/
total 88M
-rw-r--r-- 1 papermc papermc 37M Jan  6 18:01 mojang_1.16.4.jar
-rw-r--r-- 1 papermc papermc 52M Jan  6 18:01 patched_1.16.4.jar

So here alone the download and patching this mojang.jar vanilla jar exceeded the timeout, seems to be new. Not sure if internally the main jar now downloads and patches and loads another one? A that is actually exactly what Paperclip is aimed to do: https://github.com/PaperMC/Paperclip

So the download alone of course highly depends on network speed, unpredictable. I remember these Preparing spawn area phases took long when Geyser and Floodgate plugins were selected on RPi/slower devices.

Another thing, there shows up a warning when less than 1 GiB memory is used. The docs even suggest 2 GiB: https://paper.readthedocs.io/en/latest/server/getting-started.html#running-the-server
So I think 1 GiB is good to apply by default and we should assure 2 GiB overall memory being available as with this the whole process takes more than 1.3 GiB without even having any client connected.

I did another test with 256 MiB memory, and while the server starts, I see this warning:

[19:03:22 WARN]: Can't keep up! Is the server overloaded? Running 5221ms or 104 ticks behind

Additionally it takes very long to restart (to shutdown/save state, I assume). ... indeed:

Jan 06 19:08:20 VM-Buster systemd[1]: Stopping papermc (DietPi)...
Jan 06 19:09:50 VM-Buster systemd[1]: papermc.service: State 'stop-sigterm' timed out. Killing.
Jan 06 19:09:50 VM-Buster systemd[1]: papermc.service: Killing process 6758 (java) with signal SIGKILL.
Jan 06 19:09:50 VM-Buster systemd[1]: papermc.service: Main process exited, code=killed, status=9/KILL
Jan 06 19:09:50 VM-Buster systemd[1]: papermc.service: Failed with result 'timeout'.
Jan 06 19:09:50 VM-Buster systemd[1]: Stopped papermc (DietPi).

90 seconds sigterm timeout, then it is killed, which means data loss! Now raised memory to 512 MiB:

Jan 06 19:18:41 VM-Buster systemd[1]: Stopping papermc (DietPi)...
Jan 06 19:18:41 VM-Buster papermc[6915]: [19:18:41 INFO]: Stopping server
Jan 06 19:18:41 VM-Buster papermc[6915]: [19:18:41 INFO]: Saving players
Jan 06 19:18:41 VM-Buster papermc[6915]: [19:18:41 INFO]: Saving worlds
Jan 06 19:18:41 VM-Buster papermc[6915]: [19:18:41 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
Jan 06 19:18:43 VM-Buster papermc[6915]: [19:18:43 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
Jan 06 19:18:43 VM-Buster papermc[6915]: [19:18:43 INFO]: Saving chunks for level 'ServerLevel[world_nether]'/minecraft:the_nether
Jan 06 19:18:45 VM-Buster papermc[6915]: [19:18:45 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
Jan 06 19:18:45 VM-Buster papermc[6915]: [19:18:45 INFO]: Saving chunks for level 'ServerLevel[world_the_end]'/minecraft:the_end
Jan 06 19:18:45 VM-Buster papermc[6915]: [19:18:45 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
Jan 06 19:18:45 VM-Buster papermc[6915]: [19:18:45 INFO]: ThreadedAnvilChunkStorage (world): All chunks are saved
Jan 06 19:18:46 VM-Buster papermc[6915]: [19:18:46 INFO]: ThreadedAnvilChunkStorage (DIM-1): All chunks are saved
Jan 06 19:18:46 VM-Buster papermc[6915]: [19:18:46 INFO]: ThreadedAnvilChunkStorage (DIM1): All chunks are saved
Jan 06 19:18:46 VM-Buster papermc[6915]: [19:18:46 INFO]: Flushing Chunk IO
Jan 06 19:18:46 VM-Buster papermc[6915]: [19:18:46 INFO]: Closing Thread Pool
Jan 06 19:18:46 VM-Buster papermc[6915]: [19:18:46 INFO]: Closing Server
Jan 06 19:18:46 VM-Buster systemd[1]: papermc.service: Main process exited, code=exited, status=143/n/a
Jan 06 19:18:46 VM-Buster systemd[1]: papermc.service: Failed with result 'exit-code'.
Jan 06 19:18:46 VM-Buster systemd[1]: Stopped papermc (DietPi).
  • No warning about running behind and no issues when stopping the server. (Not sure why exit code is still non-zero, but thatis a different topic to ask upstream)
  • So 512 MiB can be seen as a minimum to guarantee functionality, but I think it is reasonably to have some buffer for plugins and actually attached clients and all that.

While I'm no fan of restricting the install option to fast/high RAM devices (would be difficult to maintain a list and set a border), at least we should print a warning on <2 GiB boards that the swap file will be used intensively and hence it's highly recommended to have it on an external drive to not kill the SD card. We could allow unlimited time for config file creation, but we should print the server output then, so that users can see what it's doing.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 6, 2021

or at least limit initial start up to 30 minutes? I mean it doesn't make sense to have it running for ages as it will not be no fun running such a resource consuming application on small hardware anyway.

@MichaIng
Copy link
Owner

MichaIng commented Jan 6, 2021

Agreed, a very long limit should do. Of course I agree that running it at 100% CPU usage on idle (no clients connected) already doesn't make any sense. But it's hard to define a limit. E.g. is RPi 2 fast enough or not, what if it's overclocked, fast SD card or rootfs on fast SSD together with swap file, and such. So where possible, I'd avoid hardcoding such limits and let users make their own experiences. But a warning makes sense.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 6, 2021

just to confirm, -Xmx512m is working as well on initial start-up. For sure timing to be adjusted. On my RPi3B+ it takes 190 sec including Geyser and Floodgate

+ DietPi-Software | PaperMC: reduce max java memory setting from 1024m down to 512m
+ DietPi-Software | PaperMC: ensure a memory setting of min 2GB (phys + swap). If needed, create a swap file
+ DietPi-Software | PaperMC: show an information about long start time during initial config creation
@MichaIng
Copy link
Owner

MichaIng commented Jan 11, 2021

Init command request, let's see if there is more interest than just us in such a feature: PaperMC/Paper#5046

Okay, let's finish this:

  • Shall we allow 512 MiB memory by default? It works on a fresh install, would not use a swap file on 1 GiB boards on it's own, but might fail when installing some plugins or having the server actually used by more clients.
  • Or 1024 MiB, which mutes a warning in server startup logs, should work more reliable in general, but on 1 GiB boards the swap space is written on a regular basis since the service takes overall > 1.3 GiB memory.
  • Regardless of the choice, communicating the RAM demand and how to change the limit is essential. And when we know that the swap file is used already by initial memory occupation we need to print an info/warning that this is the case and the swap file hence should hence be not located on an SD card.
  • I'll also implement a feature to watch the service start via journalctl -fu papermc & so that on slow devices users can see the actual progress.

EDIT: Ah I've overseen your last commits which already addressed the most important points 👍.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Jan 11, 2021

yeah I tried to implement some of the items we discussed. Still outstanding is the download url creation. There I'm little bit out of ideas on best way/method.

@MichaIng
Copy link
Owner

Still outstanding is the download url creation.

I'll do it, after finishing some image debootstrap tinkering. Heavily testing to create ARM images based on official Debian kernel, but it requires manual steps + U-Boot compiling often, and after wasting time on the NanoPi R4S, I recognised that my older tablet PSU is broken and I have no other sufficient one to power an RK3399... hopefully the new order arrives soon. Now redoing the same on NanoPi R2S and my brain is burning reading into a few new topics 😄.

@math-gout
Copy link
Contributor

Wouldn't it be possible to do something like this to get the latest build ?

BASE_URL='https://papermc.io/api/v2/projects/paper'
VERSION=$(curl -s $BASE_URL | jq -r '.versions[-1]')
BUILD=$(curl -s $BASE_URL/versions/$VERSION | jq -r '.builds[-1]')
NAME=$(curl -s $BASE_URL/versions/$VERSION/builds/$BUILD | jq -r '.downloads.application.name')

curl $BASE_URL/versions/$VERSION/builds/$BUILD/downloads/$NAME -o $NAME

Only downside is that you will need to install jq (apt install jq)

@MichaIng
Copy link
Owner

Nearly exactly what I had in mind, although I'll do simple bash string manipulation 😉.

@math-gout
Copy link
Contributor

math-gout commented Jan 12, 2021

Ok I've got this now, it uses curl, grep and tail.
What do you think ?

BASE_URL='https://papermc.io/api/v2/projects/paper'
VERSION=$(curl -s $BASE_URL | grep -o '[1-9\.]*' | tail -1)
BUILD=$(curl -s $BASE_URL/versions/1.16.4 | grep -o '[0-9]*' | tail -1)
NAME=paper-$VERSION-$BUILD.jar

curl $BASE_URL/versions/$VERSION/builds/$BUILD/downloads/$NAME -o $NAME

DietPi-Software | PaperMC : added new download URL to obtain latest PaperMC version
+ DietPi-Software | PaperMC : CodeFactor fix
@Joulinar
Copy link
Collaborator Author

@math-gout
thx for the idea. I added it for testing and it looks quite good.

 DietPi-Software
─────────────────────────────────────────────────────
 Mode: Installing PaperMC: Highly optimised Minecraft server with plugins, written in Java

[  OK  ] DietPi-Software | Checking URL: https://papermc.io/api/v2/projects/paper/versions/1.16.4/builds/409/downloads/paper-1.16.4-409.jar
[  OK  ] DietPi-Software | cd /tmp/DietPi-Software
[  OK  ] DietPi-Software | curl -sSfL https://papermc.io/api/v2/projects/paper/versions/1.16.4/builds/409/downloads/paper-1.16.4-409.jar -o paper-1.16.4-409.jar
[  OK  ] DietPi-Software | Verifying download target: /opt/papermc/paperclip.jar
[  OK  ] DietPi-Software | mkdir -p /opt/papermc
[  OK  ] DietPi-Software | mv paper-1.16.4-409.jar /opt/papermc/paperclip.jar

+ DietPi-Software | PaperMC : added an information about initial java memory settings and a reference to DietPi Docs on how to adjust them
@Joulinar
Copy link
Collaborator Author

@MichaIng
from my end this looks ok now, can you have a look pls

+ DietPi-Software | PaperMC: Interactively warn user already on software selection about possible swap file usage and long startup times for pre-configuration
+ DietPi-Software | Create_Config: Allow to print service journal output to console for possible time consuming startups, so that users can follow the process. Additionally stop waiting if the service is not actively running anymore, e.g. due to a crash or other unexpected stop.
+ DietPi-Software | PaperMC: Print journal output of possible long taking service startup to console
+ DietPi-Software | PaperMC: Increase swap file only to assure a minimum of 1.5 GiB memory, which is sufficient (+buffer) for starting PaperMC with 512 MiB heap size. On >2 GiB physical RAM devices, apply 1024 MiB default heap size, which should not utilise the swap file then.
+ DietPi-Software | Fix variable call
@MichaIng
Copy link
Owner

MichaIng commented Feb 1, 2021

I adjusted handling of the swap/heap size a bit and service startup output is now printed to console:

  • DietPi-Software | PaperMC: Interactively warn user already on software selection about possible swap file usage and long startup times for pre-configuration
  • DietPi-Software | Create_Config: Allow to print service journal output to console for possible time consuming startups, so that users can follow the process. Additionally stop waiting if the service is not actively running anymore, e.g. due to a crash or other unexpected stop.
  • DietPi-Software | PaperMC: Print journal output of possible long taking service startup to console
  • DietPi-Software | PaperMC: Increase swap file only to assure a minimum of 1.5 GiB memory, which is sufficient (+buffer) for starting PaperMC with 512 MiB heap size. On >2 GiB physical RAM devices, apply 1024 MiB default heap size, which should not utilise the swap file then.

And I forgot to mention the little prove of concept to derive the download URL with curl only without any additional external binary calls 😃. Practically no difference, but I like such shell magic.

@Joulinar
Copy link
Collaborator Author

Joulinar commented Feb 1, 2021

Nice idea to print service journal output 👍

Hope it is not confusing people as the server is stopp in middle of preparing spawn areas 🤔

Logfile attached. Click to expand!
[  OK  ] DietPi-Software | systemctl daemon-reload
[  OK  ] DietPi-Software | Starting PaperMC to pre-create config file in max 1800 seconds
-- Logs begin at Mon 2021-02-01 14:58:24 CET. --
Feb 01 15:36:31 DietPi4 systemd[1]: Started papermc (DietPi).
Feb 01 15:36:31 DietPi4 papermc[4716]: Downloading vanilla jar...
Feb 01 15:36:37 DietPi4 papermc[4716]: Patching vanilla jar...
Feb 01 15:36:55 DietPi4 papermc[4716]: System Info: Java 11 (OpenJDK 64-Bit Server VM 11.0.9.1+1-post-Debian-1deb10u2) Host: Linux 5.10.5-v8+ (aarch64)
Feb 01 15:36:55 DietPi4 papermc[4716]: Loading libraries, please wait...
Feb 01 15:37:12 DietPi4 papermc[4716]: [15:37:12 ERROR]: Failed to load properties from file: server.properties
Feb 01 15:37:13 DietPi4 papermc[4716]: [15:37:13 INFO]: Environment: authHost='https://authserver.mojang.com', accountsHost='https://api.mojang.com', sessionHost='https://sessionserver.mojang.com', servicesHost='https://api.minecraftservices.com', name='PROD'
Feb 01 15:37:13 DietPi4 papermc[4716]: [15:37:13 INFO]: Found new data pack file/bukkit, loading it automatically
Feb 01 15:37:14 DietPi4 papermc[4716]: [15:37:14 INFO]: Reloading ResourceManager: Default, bukkit
Feb 01 15:37:18 DietPi4 papermc[4716]: [15:37:18 INFO]: Loaded 7 recipes
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Starting minecraft server version 1.16.5
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Loading properties
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: This server is running Paper version git-Paper-457 (MC: 1.16.5) (Implementing API version 1.16.5-R0.1-SNAPSHOT)
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Console input is disabled due to --noconsole command argument
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Debug logging is disabled
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Server Ping Player Sample Count: 12
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Using 4 threads for Netty based IO
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Default game type: SURVIVAL
Feb 01 15:37:23 DietPi4 papermc[4716]: [15:37:23 INFO]: Generating keypair
Feb 01 15:37:24 DietPi4 papermc[4716]: [15:37:24 INFO]: Starting Minecraft server on *:25565
Feb 01 15:37:24 DietPi4 papermc[4716]: [15:37:24 INFO]: Using epoll channel type
Feb 01 15:37:26 DietPi4 papermc[4716]: [15:37:26 INFO]: [Geyser-Spigot] Loading Geyser-Spigot v1.2.0-SNAPSHOT
Feb 01 15:37:26 DietPi4 papermc[4716]: [15:37:26 INFO]: [floodgate-bukkit] Loading floodgate-bukkit v1.0-SNAPSHOT
Feb 01 15:37:29 DietPi4 papermc[4716]: [15:37:29 INFO]: [floodgate-bukkit] Loading Floodgate linked player database...
Feb 01 15:37:29 DietPi4 papermc[4716]: [15:37:29 INFO]: Preparing level "world"
Feb 01 15:37:46 DietPi4 papermc[4716]: [15:37:46 WARN]: Unable to find spawn biome
Feb 01 15:37:50 DietPi4 papermc[4716]: [15:37:50 WARN]: Unable to find spawn biome
Feb 01 15:37:52 DietPi4 papermc[4716]: [15:37:52 INFO]: Preparing start region for dimension minecraft:overworld
Feb 01 15:37:53 DietPi4 papermc[4716]: [15:37:53 INFO]: Loaded 0 spawn chunks for world world
Feb 01 15:37:53 DietPi4 papermc[4716]: [15:37:53 INFO]: Preparing spawn area: 0%
Feb 01 15:37:53 DietPi4 papermc[4716]: [15:37:53 INFO]: Preparing spawn area: 0%
Feb 01 15:37:53 DietPi4 papermc[4716]: [15:37:53 INFO]: Preparing spawn area: 0%
Feb 01 15:37:53 DietPi4 papermc[4716]: [15:37:53 INFO]: Preparing spawn area: 0%
Feb 01 15:37:54 DietPi4 papermc[4716]: [15:37:54 INFO]: Time elapsed: 1982 ms
Feb 01 15:37:54 DietPi4 papermc[4716]: [15:37:54 INFO]: Preparing start region for dimension minecraft:the_nether
Feb 01 15:37:55 DietPi4 papermc[4716]: [15:37:55 INFO]: Loaded 0 spawn chunks for world world_nether
Feb 01 15:37:55 DietPi4 papermc[4716]: [15:37:55 INFO]: Preparing spawn area: 0%
Feb 01 15:37:55 DietPi4 papermc[4716]: [15:37:55 INFO]: Preparing spawn area: 0%
Feb 01 15:37:55 DietPi4 papermc[4716]: [15:37:55 INFO]: Preparing spawn area: 0%
Feb 01 15:37:56 DietPi4 papermc[4716]: [15:37:55 INFO]: Preparing spawn area: 0%
Feb 01 15:37:56 DietPi4 papermc[4716]: [15:37:56 INFO]: Preparing spawn area: 0%
Feb 01 15:37:56 DietPi4 papermc[4716]: [15:37:56 INFO]: Time elapsed: 2651 ms
Feb 01 15:37:56 DietPi4 papermc[4716]: [15:37:56 INFO]: Preparing start region for dimension minecraft:the_end
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Loaded 0 spawn chunks for world world_the_end
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Preparing spawn area: 0%
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Preparing spawn area: 0%
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Preparing spawn area: 0%
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Preparing spawn area: 0%
Feb 01 15:37:58 DietPi4 papermc[4716]: [15:37:58 INFO]: Preparing spawn area: 0%
Feb 01 15:37:59 DietPi4 papermc[4716]: [15:37:59 INFO]: Preparing spawn area: 0%
Feb 01 15:38:00 DietPi4 papermc[4716]: [15:38:00 INFO]: Time elapsed: 3531 ms
Feb 01 15:38:00 DietPi4 papermc[4716]: [15:38:00 INFO]: [Geyser-Spigot] Enabling Geyser-Spigot v1.2.0-SNAPSHOT
[  ..  ]Feb 01 15:38:02 DietPi4 systemd[1]: Stopping papermc (DietPi)...
   ..   Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 INFO]: Stopping main thread (Ignore any thread death message you see! - DO NOT REPORT THREAD DEATH TO PAPER)
Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 ERROR]: Main thread terminated by WatchDog due to hard crash
Feb 01 15:38:03 DietPi4 papermc[4716]: java.lang.ThreadDeath: null
Feb 01 15:38:03 DietPi4 papermc[4716]:         at java.lang.Thread.stop(Thread.java:942) [?:?]
Feb 01 15:38:03 DietPi4 papermc[4716]:         at net.minecraft.server.v1_16_R3.MinecraftServer.stop(MinecraftServer.java:754) ~[patched_1.16.5.jar:git-Paper-457]
Feb 01 15:38:03 DietPi4 papermc[4716]:         at net.minecraft.server.v1_16_R3.DedicatedServer.stop(DedicatedServer.java:704) ~[patched_1.16.5.jar:git-Paper-457]
Feb 01 15:38:03 DietPi4 papermc[4716]:         at net.minecraft.server.v1_16_R3.MinecraftServer.close(MinecraftServer.java:728) ~[patched_1.16.5.jar:git-Paper-457]
Feb 01 15:38:03 DietPi4 papermc[4716]:         at org.bukkit.craftbukkit.v1_16_R3.util.ServerShutdownThread.run(ServerShutdownThread.java:28) ~[patched_1.16.5.jar:git-Paper-457]
Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 INFO]: Stopping server
Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 INFO]: Saving players
Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 INFO]: Saving worlds
Feb 01 15:38:03 DietPi4 papermc[4716]: [15:38:03 INFO]: Saving chunks for level 'ServerLevel[world]'/minecraft:overworld
[  OK  ] DietPi-Software | systemctl stop papermc
Feb 01 15:39:32 DietPi4 systemd[1]: papermc.service: State 'stop-sigterm' timed out. Killing.
Feb 01 15:39:32 DietPi4 systemd[1]: papermc.service: Killing process 4716 (java) with signal SIGKILL.
Feb 01 15:39:32 DietPi4 systemd[1]: papermc.service: Main process exited, code=killed, status=9/KILL
Feb 01 15:39:32 DietPi4 systemd[1]: papermc.service: Failed with result 'timeout'.
Feb 01 15:39:32 DietPi4 systemd[1]: Stopped papermc (DietPi).
[ INFO ] DietPi-Software | PaperMC config file got created after 88 seconds

@MichaIng
Copy link
Owner

MichaIng commented Feb 1, 2021

Hmm, the journalctl process was not killed as expected 🤔. Also if it get's terminated, it shows an ugly line about that.
Strange, I don't know why, but the journalctl process changes it's process ID right after it started. This doesn't happen in console, strange.

Ah found it, the $! is the PID of the [[ $output ]] check, lol.
EDIT: Fixed: f79bd8c

+ DietPi-Software | Create_Config: Fix obtaining correct PID for background journalctl to kill and kill it silently
+ DietPi-Software | PaperMC: Do not ask for EULA when it has been accepted before already
Repository owner deleted a comment from Joulinar Feb 1, 2021
@MichaIng
Copy link
Owner

MichaIng commented Feb 1, 2021

Ready for me, anything to add/test from you guys?

@MichaIng MichaIng linked an issue Feb 1, 2021 that may be closed by this pull request
@Joulinar
Copy link
Collaborator Author

Joulinar commented Feb 1, 2021

Fine for me as well

@MichaIng MichaIng merged commit 7ecb3a9 into dev Feb 2, 2021
@MichaIng MichaIng deleted the papermc branch February 2, 2021 00:01
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

PaperMC fails to install
4 participants