Server stuck for 3 hours [Simulation] "planning activity from sector (x,y,z) to (x,y,z)"

[Archer6621]

So yeah... Not sure how or why? Seems AI related to me?

This is the log from that plus moments before it started:


[2013-11-06 09:11:25] java.lang.NullPointerException
[2013-11-06 09:11:34] java.sql.SQLException: java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:11:39] at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source)
[2013-11-06 09:11:41] at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source)
[2013-11-06 09:11:47] at org.hsqldb.jdbc.JDBCStatement.fetchResult(Unknown Source)
[2013-11-06 09:11:53] at org.hsqldb.jdbc.JDBCStatement.executeQuery(Unknown Source)
[2013-11-06 09:12:00] at org.schema.game.common.controller.database.DatabaseIndex.b(SourceFile:1099)
[2013-11-06 09:12:07] at yt.run(SourceFile:82)
[2013-11-06 09:12:12] Caused by: org.hsqldb.HsqlException: java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:12:20] at org.hsqldb.error.Error.error(Unknown Source)
[2013-11-06 09:12:24] at org.hsqldb.result.Result.newErrorResult(Unknown Source)
[2013-11-06 09:12:31] at org.hsqldb.result.Result.newErrorResult(Unknown Source)
[2013-11-06 09:12:36] at org.hsqldb.Session.executeDirectStatement(Unknown Source)
[2013-11-06 09:12:42] at org.hsqldb.Session.execute(Unknown Source)
[2013-11-06 09:12:45] ... 4 more
[2013-11-06 09:12:48] Caused by: java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:12:53] java.lang.NullPointerException
[2013-11-06 09:12:56] java.lang.NullPointerException
[2013-11-06 09:13:01] java.lang.NullPointerException
[2013-11-06 09:13:08] java.lang.NullPointerException
[2013-11-06 09:13:18] java.lang.NullPointerException
[2013-11-06 09:13:24] java.lang.NullPointerException
[2013-11-06 09:13:31] RETRY STATUS: Retries: 9; waiting for pong true (1383725485586/1383725488668)
[2013-11-06 09:13:46] [TAG] WARNING: Struct read time of null took: 509
[2013-11-06 09:14:01] Exception in thread "ServerEntityWriterThread"
[2013-11-06 09:14:10] Exception in thread "pool-2-thread-2"
[2013-11-06 09:14:14] java.lang.NullPointerException
[2013-11-06 09:14:26] Exception in thread "ServerPing RegisteredClient: BusterCrab
[2013-11-06 09:14:26] b (86) connected: true"
[2013-11-06 09:14:26] java.lang.NullPointerException
[2013-11-06 09:14:27] java.lang.NullPointerException
[2013-11-06 09:14:28] java.lang.NullPointerException
[2013-11-06 09:14:33] java.lang.NullPointerException
[2013-11-06 09:14:34] java.lang.NullPointerException
[2013-11-06 09:14:38] java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:14:38] Exception in thread "pool-2-thread-5"
[2013-11-06 09:14:38] Exception in thread "ServerController"
[2013-11-06 09:14:39] java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:14:41] java.lang.NullPointerException
[2013-11-06 09:14:43] java.lang.NullPointerException
[2013-11-06 09:14:46] java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:14:46] java.lang.NullPointerException
[2013-11-06 09:14:48] java.lang.NullPointerException
[2013-11-06 09:14:49] java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:14:49] java.lang.NullPointerException
[2013-11-06 09:14:50] java.lang.OutOfMemoryError: Java heap space
[2013-11-06 09:14:50] java.lang.NullPointerException
[2013-11-06 09:14:50] java.lang.NullPointerException
[2013-11-06 09:14:50] SENDING THREAD ENDED of RegisteredClient: BusterCrabb (86) connected: true
[2013-11-06 09:14:50] java.net.SocketException: Connection reset
[2013-11-06 09:14:50] at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118)
[2013-11-06 09:14:50] at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
[2013-11-06 09:14:50] at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
[2013-11-06 09:14:50] at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
[2013-11-06 09:14:50] at java.io.DataOutputStream.flush(DataOutputStream.java:123)
[2013-11-06 09:14:50] at org.schema.schine.network.server.ServerProcessor$SendingQueueThread.run(SourceFile:115)
[2013-11-06 09:14:50] [SERVER][DISCONNECT] Client 'RegisteredClient: BusterCrabb (86) connected: true' HAS BEEN DISCONNECTED . PROBE: false
[2013-11-06 09:14:50] [SERVER] Client logged out from server. connections count: 188
[2013-11-06 09:14:50] [SERVER] UNREGISTERING CLIENT RegisteredClient: BusterCrabb (86) connected: true
[2013-11-06 09:14:50] [SERVER] UNREGISTER DONE FOR CLIENT RegisteredClient: BusterCrabb (86) connected: true
[2013-11-06 09:14:50] [SERVER] SERVER PROCESSOR STOPPED FOR RegisteredClient: BusterCrabb (86) connected: true
[2013-11-06 09:17:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:21:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:26:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:30:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:35:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:39:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:44:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:48:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:53:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 09:57:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:02:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:06:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:11:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:15:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:20:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:24:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:29:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:33:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:38:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:42:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:47:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:51:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 10:56:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:00:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:05:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:09:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:14:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:18:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:23:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:27:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:32:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:36:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:41:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:45:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:50:23] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)
[2013-11-06 11:54:53] [SIMULATION] checking sectors to plan activity.... (8, 4, 7) to (16, 12, 15)






I noticed the out of memory thing as well, but with such few players (maybe 3-4 at that time), tell me how StarMade can eat up to 4gb memory? Sounds a bit like some sort of memory leak.

Also notice that the server stopped as soon as that player joined, does this have to do with the source of lag on player join? (This was fixed in the prebuilds I saw)

 

[MichaelSeph]

When there are those lines saying 2 sector coordinates with exactly 8 8 8 difference between them [in this case, (8, 4, 7) to (16, 12, 15) ], and takes too long (but, normally just 30 seconds or such), is when a new player uses the map for the first time, and starts generating certain cache for him, as well as reading all those sectors at once (including pirates), 512 of them, the map actually shows the icons of what\'s in 16x16x16 sectors that is a solar system. Yours went out of momory while doing it.

As mentioned, it only causes a little issue the first time one player uses it. The next times, it will work smoothly, no matter they reconnected or just left and joined in next week to try this.

 

[Archer6621]

So in other words: this is fixed in the latest available prebuild?

 

[MichaelSeph]

It is supposed to give a fix, but I\'m not sure if the fix/optimization of this is already released in the last prebuild or not.

 

[Archer6621]

Okay, thanks a lot for the help