On a whim, I decided to see what happens on a clean/new install, after deleting server-database, and replacing that path with the contents of an update's forced backup.
Two main issues, one is illustrated in T1987, repeated here:
~$ du --max-depth=1 -h prodStarmade/StarMade/server-database/ stageStarmade/StarMade/server-database/ 17G prodStarmade/StarMade/server-database/world0 17G prodStarmade/StarMade/server-database/ 129G stageStarmade/StarMade/server-database/world0 129G stageStarmade/StarMade/server-database/
stageStarmade is the extract of backup-StarMade-0.199.217-20160910_183953_1474676851924.zip You'll notice the lack of pkzip's support for sparse files, and therefore the very large disk space consumption discrepancy between prodStarmade and stageStarmade
The other issue, is that the server will begin reporting thousands upon thousands of lines containing just:
RECORDING SIZE!!!
...more accurately stated, there were 34,421 such lines created in the span of approximately 10 minutes.
After waiting for nearly 2 hours, the server did finally stop reporting that string, and attempts to login no longer encountered the "SocketTimeoutException: Failed to connect!" error.
serverlog.0.log was empty during this time
The rest of the logstarmade.0.log consisted of:
[2016-10-05 21:18:12] [VERSION] loading version from install dir: ./ [2016-10-05 21:18:12] [VERSION] VERSION: 0.199.234 [2016-10-05 21:18:12] [VERSION] BUILD: 20160924_005306 [2016-10-05 21:18:12] #################### StarMade ####################### [2016-10-05 21:18:12] # version 0.199.234 - build 20160924_005306 # [2016-10-05 21:18:12] ##################################################### [2016-10-05 21:18:12] [SERIAL] "not retrieved" [2016-10-05 21:18:12] [INSTALLATION_DIRECTORY] "/opt/stageStarmade/StarMade/." [2016-10-05 21:18:12] [TEXTURE-PACK] WARNING: ignoring shield_tex.png.zip: not a directory [2016-10-05 21:18:12] [TEXTURE-PACK] WARNING: ignoring lava.png.zip: not a directory [2016-10-05 21:18:12] [TEXTURE-PACK] WARNING: ignoring shield_tex.png.zip: not a directory [2016-10-05 21:18:12] [TEXTURE-PACK] WARNING: ignoring lava.png.zip: not a directory [2016-10-05 21:18:12] java.io.FileNotFoundException: ./settings.cfg (No such file or directory) [2016-10-05 21:18:12] at java.io.FileInputStream.open0(Native Method) [2016-10-05 21:18:12] at java.io.FileInputStream.open(FileInputStream.java:195) [2016-10-05 21:18:12] at java.io.FileInputStream.<init>(FileInputStream.java:138) [2016-10-05 21:18:12] at java.io.FileReader.<init>(FileReader.java:72) [2016-10-05 21:18:12] at obfuscated.aAU.b(SourceFile:572) [2016-10-05 21:18:12] at obfuscated.aAU.d(SourceFile:614) [2016-10-05 21:18:12] at org.schema.game.common.Starter.main(SourceFile:822) [2016-10-05 21:18:12] Could not read settings file: using defaults [2016-10-05 21:18:12] [STARTER] template dir exists. overwriting template with current data [2016-10-05 21:18:12] [IO][COPY] FILE FROM /opt/stageStarmade/StarMade/./data/config/FactionConfig.xml to /opt/stageStarmade/StarMade/./customFactionConfig/FactionConfigTemplate.xml [2016-10-05 21:18:12] [IO][COPY] FILE FROM /opt/stageStarmade/StarMade/./data/config/customFactionConfigHOWTO.txt to /opt/stageStarmade/StarMade/./customFactionConfig/customFactionConfigHOWTO.txt [2016-10-05 21:18:12] [STARTER] template dir exists. overwriting template with current data [2016-10-05 21:18:12] [IO][COPY] FILE FROM /opt/stageStarmade/StarMade/./data/config/customBlockBehaviorConfigTemplate.xml to /opt/stageStarmade/StarMade/./customBlockBehaviorConfig/customBlockBehaviorConfigTemplate.xml [2016-10-05 21:18:12] [IO][COPY] FILE FROM /opt/stageStarmade/StarMade/./data/config/customBlockBehaviorConfigHOWTO.txt to /opt/stageStarmade/StarMade/./customBlockBehaviorConfig/customBlockBehaviorConfigHOWTO.txt [2016-10-05 21:18:12] [RESOURCES][CustomTextures] No need to create pack.zip. Hash matches (as rewriting a zip changes the hash on it) [2016-10-05 21:18:12] [LANGUAGE] detected language: en [2016-10-05 21:18:12] [LANGUAGE] loading language: english; Resolved to english [2016-10-05 21:18:12] java.io.FileNotFoundException: ./keyboard.cfg (No such file or directory) [2016-10-05 21:18:12] at java.io.FileInputStream.open0(Native Method) [2016-10-05 21:18:12] at java.io.FileInputStream.open(FileInputStream.java:195) [2016-10-05 21:18:12] at java.io.FileInputStream.<init>(FileInputStream.java:138) [2016-10-05 21:18:12] at java.io.FileReader.<init>(FileReader.java:72) [2016-10-05 21:18:12] at org.schema.schine.input.KeyboardMappings.a(SourceFile:182) [2016-10-05 21:18:12] at obfuscated.Uv.b(SourceFile:93) [2016-10-05 21:18:12] at obfuscated.Uv.a(SourceFile:228) [2016-10-05 21:18:12] at org.schema.game.common.Starter.main(SourceFile:825) [2016-10-05 21:18:12] Could not read settings file: using defaults (./keyboard.cfg (No such file or directory)) [2016-10-05 21:18:12] [LANGUAGE] Loading English; Version: 0 [2016-10-05 21:18:12] [LANGUAGE] LOADED FONT PATH/NAME: font/Monda-Regular.ttf [2016-10-05 21:18:13] [SERVER] using world: world0; ./server-database/world0/ [2016-10-05 21:18:13] [INIT] Segment Database Path: /opt/stageStarmade/StarMade/./server-database/world0/DATA; exists? true; is Dir? true; creating dir sucessfull (gives false if exists)? false [2016-10-05 21:18:13] [GUI] NO STARMADE-WINDOW CONFIG FOUND. Using defaults [2016-10-05 21:18:13] [LIBLOADER] OS Linux - 2.6.32-042stab117.14 [2016-10-05 21:18:13] [LIBLOADER] JAVA Oracle Corporation - 1.8.0_92 - /usr/java/jdk1.8.0_92/jre [2016-10-05 21:18:13] [LIBLOADER] ARCHITECTURE amd64 [2016-10-05 21:18:13] [LIBLOADER] LOADED LINUX 64bit NATIVE LIBRARIES [2016-10-05 21:18:13] [LIBLOADER] FastNoiseSIMD Level: 2 [2016-10-05 21:18:13] [LIBLOADER] COMPLETE [2016-10-05 21:18:13] [MAIN] CHECKING IF MIGRATION NECESSARY [2016-10-05 21:18:13] [MAIN] MIGRATION PROCESS DONE [2016-10-05 21:18:13] [MAIN] STARTING WITH ARGUMENTS: [-server, -port:4848] [2016-10-05 21:18:13] [MAIN] LOADED ENGINE SETTINGS [2016-10-05 21:18:13] [INITIALIZE] REMOTE CLASSES REGISTERED [2016-10-05 21:18:13] [INITIALIZE] RESOURCE MANAGER INITIALIZED [2016-10-05 21:18:13] ERROR: no content in Resource: /opt/stageStarmade/StarMade/file:/opt/stageStarmade/StarMade/StarMade.jar!/org/schema/game/network/commands [2016-10-05 21:18:13] ################# Loading from JAR ##################### [2016-10-05 21:18:13] ######################################################## [2016-10-05 21:18:13] [INITIALIZE] REMOTE COMMANDS REGISTERED [2016-10-05 21:18:13] [INITIALIZE] SECURITY MANAGER SET [2016-10-05 21:18:13] [INITIALIZE] COMMAND ID's ASSIGNED. NOW READING BLOCK CONFIG [2016-10-05 21:18:13] [INITIALIZE] BLOCK CONFIGURATION READ [2016-10-05 21:18:13] [BLUEPRINT][MIGRATION] NO CONVERSION NEEDED: no old bb file exists: /opt/stageStarmade/StarMade/./blueprints/catalog.txt [2016-10-05 21:18:14] [SERVER] ###### READING ALL BLUEPRINTS! [2016-10-05 21:18:14] [SERVER] ###### READING ALL 16 BLUEPRINTS FINISHED! TOOK 28ms [2016-10-05 21:18:14] DOING TAG DATABASE MIGRATION (this can take a little) [DO NOT KILL THE PROCESS] [2016-10-05 21:18:14] [MIGRATION] REMOVING UNNECESSARY SHOP RAW BLOCK DATA. FILES FOUND: 0 [2016-10-05 21:18:14] [MIGRATION] REMOVING UNNECESSARY SHOP RAW BLOCK DATA DONE [2016-10-05 21:18:14] [MIGRATION] MIGRATING META-DATA STRUCTURE (can take very long) [2016-10-05 21:18:14] [TAG] WARNING STRUCT DESERIALIZATION took too long: 70; [2016-10-05 21:18:25] [TAG] WARNING STRUCT DESERIALIZATION took too long: 33; [2016-10-05 21:18:25] [TAG] WARNING STRUCT DESERIALIZATION took too long: 34; [2016-10-05 21:18:25] [TAG] WARNING STRUCT DESERIALIZATION took too long: 34; [2016-10-05 21:18:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 39; [2016-10-05 21:18:49] [TAG] WARNING STRUCT DESERIALIZATION took too long: 46; [2016-10-05 21:19:00] [TAG] WARNING STRUCT DESERIALIZATION took too long: 39; [2016-10-05 21:19:12] [TAG] WARNING: Struct read time of cs1 took: 106 [2016-10-05 21:19:12] [TAG] WARNING STRUCT DESERIALIZATION took too long: 109; [2016-10-05 21:19:12] [TAG] warning: reading tag: sc took: 109 [2016-10-05 21:19:28] [TAG] WARNING: Struct read time of cs1 took: 115 [2016-10-05 21:19:28] [TAG] WARNING STRUCT DESERIALIZATION took too long: 117; [2016-10-05 21:19:28] [TAG] warning: reading tag: sc took: 117 [2016-10-05 21:19:29] [TAG] WARNING: Struct read time of cs1 took: 116 [2016-10-05 21:19:29] [TAG] WARNING STRUCT DESERIALIZATION took too long: 118; [2016-10-05 21:19:29] [TAG] warning: reading tag: sc took: 118 [2016-10-05 21:19:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 35; [2016-10-05 21:19:48] [TAG] WARNING STRUCT DESERIALIZATION took too long: 36; [2016-10-05 21:19:51] [TAG] WARNING STRUCT DESERIALIZATION took too long: 31; [2016-10-05 21:19:51] [TAG] WARNING STRUCT DESERIALIZATION took too long: 31; [2016-10-05 21:19:51] [TAG] WARNING STRUCT DESERIALIZATION took too long: 34; [2016-10-05 21:19:51] [TAG] WARNING STRUCT DESERIALIZATION took too long: 92; [2016-10-05 21:20:04] [TAG] WARNING STRUCT DESERIALIZATION took too long: 94; [2016-10-05 21:20:13] [TAG] WARNING STRUCT DESERIALIZATION took too long: 33; [2016-10-05 21:20:19] [TAG] WARNING: Struct read time of cs1 took: 242 [2016-10-05 21:20:19] [TAG] WARNING STRUCT DESERIALIZATION took too long: 244; [2016-10-05 21:20:19] [TAG] WARNING: Struct read time of s3 took: 244 [2016-10-05 21:20:19] [TAG] WARNING STRUCT DESERIALIZATION took too long: 245; [2016-10-05 21:20:19] [TAG] warning: reading tag: SpaceStation took: 245 [2016-10-05 21:20:26] [TAG] WARNING STRUCT DESERIALIZATION took too long: 80; [2016-10-05 21:20:26] [TAG] WARNING STRUCT DESERIALIZATION took too long: 81; [2016-10-05 21:20:42] [TAG] WARNING STRUCT DESERIALIZATION took too long: 45; [2016-10-05 21:20:53] [TAG] WARNING STRUCT DESERIALIZATION took too long: 76; [2016-10-05 21:20:57] [TAG] WARNING STRUCT DESERIALIZATION took too long: 78; [2016-10-05 21:20:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 68; [2016-10-05 21:21:08] [TAG] WARNING STRUCT DESERIALIZATION took too long: 74; [2016-10-05 21:21:17] [TAG] WARNING STRUCT DESERIALIZATION took too long: 92; [2016-10-05 21:21:29] [TAG] WARNING: Struct read time of cs1 took: 144 [2016-10-05 21:21:29] [TAG] WARNING STRUCT DESERIALIZATION took too long: 144; [2016-10-05 21:21:29] [TAG] warning: reading tag: sc took: 145 [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of null took: 271 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 272; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of null took: 272 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 273; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of null took: 273 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of null took: 275 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of null took: 275 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of exS took: 275 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of container took: 275 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] WARNING: Struct read time of sc took: 275 [2016-10-05 21:21:58] [TAG] WARNING STRUCT DESERIALIZATION took too long: 275; [2016-10-05 21:21:58] [TAG] warning: reading tag: Planet took: 275 [2016-10-05 21:22:29] [TAG] WARNING STRUCT DESERIALIZATION took too long: 72; [2016-10-05 21:22:50] [TAG] WARNING STRUCT DESERIALIZATION took too long: 53; [2016-10-05 21:22:57] [TAG] WARNING STRUCT DESERIALIZATION took too long: 62; [2016-10-05 21:23:41] [TAG] WARNING STRUCT DESERIALIZATION took too long: 32; [2016-10-05 21:24:02] [TAG] WARNING STRUCT DESERIALIZATION took too long: 83; [2016-10-05 21:24:02] [TAG] WARNING STRUCT DESERIALIZATION took too long: 86; [2016-10-05 21:24:04] [TAG] WARNING STRUCT DESERIALIZATION took too long: 85; [2016-10-05 21:24:04] [TAG] WARNING STRUCT DESERIALIZATION took too long: 88; [2016-10-05 21:24:12] [TAG] WARNING STRUCT DESERIALIZATION took too long: 73; [2016-10-05 21:24:19] [TAG] WARNING STRUCT DESERIALIZATION took too long: 79; [2016-10-05 21:24:22] [TAG] WARNING STRUCT DESERIALIZATION took too long: 81; [2016-10-05 21:24:43] [TAG] WARNING: Struct read time of cs1 took: 119 [2016-10-05 21:24:43] [TAG] WARNING STRUCT DESERIALIZATION took too long: 119; [2016-10-05 21:24:43] [TAG] warning: reading tag: sc took: 119 [2016-10-05 21:24:54] [TAG] WARNING: Struct read time of cs1 took: 109 [2016-10-05 21:24:54] [TAG] WARNING STRUCT DESERIALIZATION took too long: 110; [2016-10-05 21:24:54] [TAG] warning: reading tag: sc took: 110 [2016-10-05 21:25:33] [TAG] WARNING STRUCT DESERIALIZATION took too long: 32; [2016-10-05 21:25:41] [TAG] WARNING STRUCT DESERIALIZATION took too long: 68; [2016-10-05 21:25:48] [TAG] WARNING STRUCT DESERIALIZATION took too long: 71; [2016-10-05 21:25:50] [TAG] WARNING: Struct read time of cs1 took: 122 [2016-10-05 21:25:50] [TAG] WARNING STRUCT DESERIALIZATION took too long: 123; [2016-10-05 21:25:50] [TAG] warning: reading tag: sc took: 123 [2016-10-05 21:26:01] [TAG] WARNING: Struct read time of cs1 took: 129 [2016-10-05 21:26:01] [TAG] WARNING STRUCT DESERIALIZATION took too long: 130; [2016-10-05 21:26:01] [TAG] warning: reading tag: sc took: 130 [2016-10-05 21:26:06] [TAG] WARNING STRUCT DESERIALIZATION took too long: 96; [2016-10-05 21:26:19] [TAG] WARNING: Struct read time of cs1 took: 101 [2016-10-05 21:26:19] [TAG] WARNING STRUCT DESERIALIZATION took too long: 101; [2016-10-05 21:26:19] [TAG] warning: reading tag: sc took: 101 [2016-10-05 21:26:26] [TAG] WARNING STRUCT DESERIALIZATION took too long: 38; [2016-10-05 21:26:30] [TAG] WARNING STRUCT DESERIALIZATION took too long: 69; [2016-10-05 21:26:59] [TAG] WARNING STRUCT DESERIALIZATION took too long: 100; [2016-10-05 21:27:15] [TAG] WARNING: Struct read time of cs1 took: 173 [2016-10-05 21:27:15] [TAG] WARNING STRUCT DESERIALIZATION took too long: 174; [2016-10-05 21:27:15] [TAG] warning: reading tag: sc took: 174 [2016-10-05 21:27:35] [TAG] WARNING STRUCT DESERIALIZATION took too long: 79; [2016-10-05 21:27:38] [TAG] WARNING STRUCT DESERIALIZATION took too long: 81; [2016-10-05 21:27:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 94; [2016-10-05 21:27:55] [TAG] WARNING: Struct read time of cs1 took: 163 [2016-10-05 21:27:55] [TAG] WARNING STRUCT DESERIALIZATION took too long: 164; [2016-10-05 21:27:55] [TAG] warning: reading tag: sc took: 164 [2016-10-05 21:27:57] [TAG] WARNING STRUCT DESERIALIZATION took too long: 68; [2016-10-05 21:27:59] [TAG] WARNING STRUCT DESERIALIZATION took too long: 39; [2016-10-05 21:28:03] [TAG] WARNING STRUCT DESERIALIZATION took too long: 40; [2016-10-05 21:28:06] EXCEPTION IN null; array index: 108 [2016-10-05 21:28:06] EXCEPTION IN null; array index: 2 [2016-10-05 21:28:06] EXCEPTION IN null; array index: 1 [2016-10-05 21:28:06] EXCEPTION IN exS; array index: 4 [2016-10-05 21:28:06] EXCEPTION IN container; array index: 0 [2016-10-05 21:28:06] EXCEPTION WHILE READING TAG SpaceStation [2016-10-05 21:28:06] java.io.EOFException [2016-10-05 21:28:06] at java.io.DataInputStream.readByte(DataInputStream.java:267) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:631) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:647) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:647) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:647) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:647) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:647) [2016-10-05 21:28:06] at obfuscated.aKT.a(SourceFile:462) [2016-10-05 21:28:06] at org.schema.game.common.Starter.dbShopAndTagMigration(SourceFile:644) [2016-10-05 21:28:06] at org.schema.game.common.Starter.doMigration(SourceFile:541) [2016-10-05 21:28:06] at org.schema.game.common.Starter.main(SourceFile:942) [2016-10-05 21:28:17] [TAG] WARNING STRUCT DESERIALIZATION took too long: 57; [2016-10-05 21:28:25] [TAG] WARNING: Struct read time of cs1 took: 125 [2016-10-05 21:28:25] [TAG] WARNING STRUCT DESERIALIZATION took too long: 125; [2016-10-05 21:28:25] [TAG] warning: reading tag: sc took: 125 [2016-10-05 21:28:36] [TAG] WARNING: Struct read time of cs1 took: 147 [2016-10-05 21:28:36] [TAG] WARNING STRUCT DESERIALIZATION took too long: 147; [2016-10-05 21:28:36] [TAG] warning: reading tag: sc took: 147 [2016-10-05 21:28:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 78; [2016-10-05 21:28:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 79; [2016-10-05 21:28:48] [TAG] WARNING STRUCT DESERIALIZATION took too long: 100; [2016-10-05 21:28:48] [TAG] WARNING STRUCT DESERIALIZATION took too long: 101; [2016-10-05 21:28:48] [TAG] warning: reading tag: SpaceStation took: 101 [2016-10-05 21:29:36] [TAG] WARNING: Struct read time of cs1 took: 364 [2016-10-05 21:29:36] [TAG] WARNING STRUCT DESERIALIZATION took too long: 365; [2016-10-05 21:29:36] [TAG] warning: reading tag: s3 took: 365 [2016-10-05 21:29:49] [TAG] WARNING: Struct read time of cs1 took: 163 [2016-10-05 21:29:49] [TAG] WARNING STRUCT DESERIALIZATION took too long: 164; [2016-10-05 21:29:49] [TAG] warning: reading tag: s3 took: 164 [2016-10-05 21:29:51] [TAG] WARNING STRUCT DESERIALIZATION took too long: 68; [2016-10-05 21:29:53] [TAG] WARNING: Struct read time of cs1 took: 501 [2016-10-05 21:29:53] [TAG] WARNING STRUCT DESERIALIZATION took too long: 504; [2016-10-05 21:29:53] [TAG] WARNING: Struct read time of sc took: 504 [2016-10-05 21:29:53] [TAG] WARNING STRUCT DESERIALIZATION took too long: 508; [2016-10-05 21:29:53] [TAG] warning: reading tag: SpaceStation took: 508 [2016-10-05 21:29:56] [TAG] WARNING STRUCT DESERIALIZATION took too long: 33; [2016-10-05 21:29:56] [TAG] WARNING STRUCT DESERIALIZATION took too long: 37; [2016-10-05 21:30:03] [TAG] WARNING STRUCT DESERIALIZATION took too long: 78; [2016-10-05 21:30:14] [TAG] WARNING: Struct read time of cs1 took: 279 [2016-10-05 21:30:14] [TAG] WARNING STRUCT DESERIALIZATION took too long: 282; [2016-10-05 21:30:14] [TAG] WARNING: Struct read time of s3 took: 283 [2016-10-05 21:30:14] [TAG] WARNING STRUCT DESERIALIZATION took too long: 286; [2016-10-05 21:30:14] [TAG] warning: reading tag: SpaceStation took: 286 [2016-10-05 21:30:23] [TAG] WARNING STRUCT DESERIALIZATION took too long: 39; [2016-10-05 21:30:44] [TAG] WARNING STRUCT DESERIALIZATION took too long: 33; [2016-10-05 21:30:48] [TAG] WARNING STRUCT DESERIALIZATION took too long: 36; [2016-10-05 21:30:50] [TAG] WARNING STRUCT DESERIALIZATION took too long: 78;
I thought that perhaps the game engine was re-compacting all sparse files...but after waiting hours, and multiple restart tests later, there was no sign of recompaction.