Starmade | Loading sector causes mass timeouts with colliding asteroids
Resolved, needs quality check / confirm fix, UrgentPublic
Actions

Description

Loading this sector causes the server to timeout all logged-in players. Looks like a bunch of asteroids spawned-into it.

RoidCrash.smsec4 KBDownload

Jul  9 02:12:29 stars SMPrd: Sector[12651](11, 36, 3) Narrowphase of Sector[12651](11, 36, 3) took: 2766
Jul  9 02:12:29 stars SMPrd: Sector[12651](11, 36, 3) LISTING OBJECTS:
Jul  9 02:12:29 stars SMPrd: 0# OBJECT: {RigBExOrig@81808299([CCS|SER Ship[MahRocket](4065)])}
Jul  9 02:12:29 stars SMPrd: 1# OBJECT: {RigBExOrig@1842474665([CCS|SER Asteroid(12658)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 2# OBJECT: {RigBExOrig@1235254324([CCS|SER Asteroid(12665)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 3# OBJECT: {RigBExOrig@1339191604([CCS|SER Asteroid(12663)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 4# OBJECT: {RigBExOrig@98166054([CCS|SER Asteroid(12661)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 5# OBJECT: {RigBExOrig@2017532867([CCS|SER Asteroid(12664)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 6# OBJECT: {RigBExOrig@445060804([CCS|SER Asteroid(12656)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 7# OBJECT: {RigBExOrig@1174445937([CCS|SER Asteroid(12654)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 8# OBJECT: {RigBExOrig@205169218([CCS|SER Asteroid(12657)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 9# OBJECT: {RigBExOrig@75445061([CCS|SER Asteroid(12662)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 10# OBJECT: {RigBExOrig@2094350085([CCS|SER Asteroid(12660)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 11# OBJECT: {RigBExOrig@1590048621([CCS|SER Asteroid(12659)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 12# OBJECT: {RigBExOrig@486527187([CCS|SER Asteroid(12655)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 13# OBJECT: {RigBExOrig@1158568380([CCS|SER Asteroid(12652)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 14# OBJECT: {RigBExOrig@284584719([CCS|SER Asteroid(12653)sec[12651]])}
Jul  9 02:12:29 stars SMPrd: 15# OBJECT: {RigBExvirtS(ori)(10, 37, 2)mapTo(vi)(11, 36, 3){{RigBExOrig@1388711060([CCS|SER Planet(12707)[s12706]none])}}@2145671971([CCS|SER Planet(12707)[s12706]none])}
Jul  9 02:12:29 stars SMPrd: 16# OBJECT: {RigBExvirtS(ori)(10, 36, 4)mapTo(vi)(11, 36, 3){{RigBExOrig@854210982([CCS|SER Planet(12702)[s12685]none])}}@503280964([CCS|SER Planet(12702)[s12685]none])}

RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_6, sectorPos=(11, 36, 3), type=3, seed=3114645748701364969, lastModifier=, spawner=, realName=Asteroid (rich in Parseen, Sapsun), touched=false, faction=0, pos=(281.2945, 342.51517, 323.20123), minPos=(-3, -6, -4), maxPos=(2, 5, 3), creatorID=5], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_3, sectorPos=(11, 36, 3), type=3, seed=-1337967039910269201, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(239.13359, 318.49146, -117.70675), minPos=(-5, -4, -6), maxPos=(4, 3, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_3, sectorPos=(11, 36, 3), type=3, seed=-1337967039910269201, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(242.2374, 308.21988, -108.5834), minPos=(-5, -4, -6), maxPos=(4, 3, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_0, sectorPos=(11, 36, 3), type=3, seed=3344740543496289865, lastModifier=, spawner=, realName=Asteroid (rich in Rammet, Sertise), touched=false, faction=0, pos=(-257.20413, -163.88069, -143.35858), minPos=(-4, -6, -6), maxPos=(3, 5, 5), creatorID=7], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_5, sectorPos=(11, 36, 3), type=3, seed=-5280258136270619386, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-314.47284, 176.36885, 323.39764), minPos=(-3, -6, -6), maxPos=(2, 5, 5), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_5, sectorPos=(11, 36, 3), type=3, seed=-5280258136270619386, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-304.2541, 187.35738, 337.41), minPos=(-3, -6, -6), maxPos=(2, 5, 5), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_2, sectorPos=(11, 36, 3), type=3, seed=6075141803062040085, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(-363.9849, -306.10913, 306.95834), minPos=(-3, -5, -6), maxPos=(2, 4, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_2, sectorPos=(11, 36, 3), type=3, seed=6075141803062040085, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(-324.12177, -298.4089, 312.87527), minPos=(-3, -5, -6), maxPos=(2, 4, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_6, sectorPos=(11, 36, 3), type=3, seed=3114645748701364969, lastModifier=, spawner=, realName=Asteroid (rich in Parseen, Sapsun), touched=false, faction=0, pos=(308.99567, 355.78857, 345.85458), minPos=(-3, -6, -4), maxPos=(2, 5, 3), creatorID=5], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_1, sectorPos=(11, 36, 3), type=3, seed=-111421776669247164, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(283.2046, -109.47287, -36.91796), minPos=(-3, -6, -5), maxPos=(2, 5, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_4, sectorPos=(11, 36, 3), type=3, seed=-3529445318389979827, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-252.10196, 284.7759, -118.6858), minPos=(-4, -4, -5), maxPos=(3, 3, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480633_11_36_3_1, sectorPos=(11, 36, 3), type=3, seed=-111421776669247164, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(307.07913, -125.79466, -20.128979), minPos=(-3, -6, -5), maxPos=(2, 5, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_4, sectorPos=(11, 36, 3), type=3, seed=-3529445318389979827, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-251.2003, 259.7835, -127.59725), minPos=(-4, -4, -5), maxPos=(3, 3, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480633_11_36_3_0, sectorPos=(11, 36, 3), type=3, seed=3344740543496289865, lastModifier=, spawner=, realName=Asteroid (rich in Rammet, Sertise), touched=false, faction=0, pos=(-264.1125, -177.01012, -156.30392), minPos=(-4, -6, -6), maxPos=(3, 5, 5), creatorID=7], 0]
RETURN: [SERVER, SECTOR INFO: Sector[12882](11, 36, 3); Protected: false; Peace: false; Seed: 0; Type: ASTEROID;, 0]
RETURN: [SERVER, END; Admin command execution ended, 0]

Details

Commits: Restricted Diffusion Commit
Task Type: Bug

Testing Results

Affected Gamemode(s): Single and Multi
Reproducible: Not on purpose
Last tested (version): 0.199.491
Category: Physics
First occurrence (version): 0.198.419

Hardware/Software/System

OS-Specific: No
Hardware-Specific: No
Video Card Vendor: uncertain

Tester information (Internal use only)

Partial fix.

It seems to get stuck in a loop of avoiding collisions, and then resetting to that state just to start it all over again.
Asteroids get pushed away (as far as I can see at least), but they get reverted back to their original colliding position which triggers the same thing again after a few seconds.

It may be the lag compensation kicking in and putting it back where it came from, at least it looks like that as if you teleported a big ship to another local sector position.
Some logs that may help:

logstarmade.0.log3 MBDownload

You can reproduce this by importing and loading the sector provided in the description:

RoidCrash.smsec4 KBDownload

Serverconfig (server.cfg)

<replace this line with the file content>

Clientconfig (settings.cfg)

<replace this line with the file content>

Related Objects

Mentioned In: T1409: Respawning asteroids causes server lag
T1557: asteroid generation not working

Event Timeline

erthparadine created this task.Jul 9 2016, 2:18 AM

SmilingDemon claimed this task.Jul 9 2016, 1:57 PM

A possibly related element, as suggested by @SmilingDemon in slack: two players did in-fact login at seemingly the same time, at near the same sector, when the lagoff began.

SmilingDemon shifted this object from the S1 Public space to the S3 Starmade space.Jul 9 2016, 2:18 PM

SmilingDemon changed the visibility from "Custom Policy" to "Public (No Login Required)".

SmilingDemon changed the edit policy from "Task Author" to "Starmade (Project)".

SmilingDemon edited Tester information (Internal use only). (Show Details)

SmilingDemon changed Affected Gamemode(s) from none/unspecified to Single and Multi.

SmilingDemon changed Reproducible from uncertain to Not on purpose.

SmilingDemon set Last tested (version) to 0.198.419 (DEV).

SmilingDemon changed Category from none/unspecified to Universe.

SmilingDemon triaged this task as Urgent priority.

Restricted Application added a subscriber: AndyP. · View Herald TranscriptJul 9 2016, 2:18 PM

loading in that sector shows a lot of broken asteroids .. and pretty small ones. No collisions however

That's odd, and not what I'm seeing in our world. I'll grab & upload a video when our player count drops low for the day.

SmilingDemon edited Tester information (Internal use only). (Show Details)Jul 9 2016, 2:23 PM

The two involved players have not relogged since the lagoff, but I will reach out to them if/when they do.

did you force save and then made an export ?
or waited until the lag spike was gone ?

Hmm, I had just run an export while visiting that sector for the first time, and seeing the lag spike. Since its been ~12 hours, with one scheduled server restart during that time, here's another export.

RoidLagoff2.smsec4 KBDownload

RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_3, sectorPos=(11, 36, 3), type=3, seed=-1337967039910269201, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(239.13359, 318.49146, -117.70675), minPos=(-5, -4, -6), maxPos=(4, 3, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_2, sectorPos=(11, 36, 3), type=3, seed=6075141803062040085, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(-324.12177, -298.4089, 312.87527), minPos=(-3, -5, -6), maxPos=(2, 4, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_5, sectorPos=(11, 36, 3), type=3, seed=-5280258136270619386, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-304.2541, 187.35738, 337.41), minPos=(-3, -6, -6), maxPos=(2, 5, 5), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_1, sectorPos=(11, 36, 3), type=3, seed=-111421776669247164, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(283.2046, -109.47287, -36.91796), minPos=(-3, -6, -5), maxPos=(2, 5, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247925_11_36_3_0, sectorPos=(11, 36, 3), type=3, seed=3344740543496289865, lastModifier=, spawner=, realName=Asteroid (rich in Rammet, Sertise), touched=false, faction=0, pos=(-257.20413, -163.88069, -143.35858), minPos=(-4, -6, -6), maxPos=(3, 5, 5), creatorID=7], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_6, sectorPos=(11, 36, 3), type=3, seed=3114645748701364969, lastModifier=, spawner=, realName=Asteroid (rich in Parseen, Sapsun), touched=false, faction=0, pos=(281.2945, 342.51517, 323.20123), minPos=(-3, -6, -4), maxPos=(2, 5, 3), creatorID=5], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1467881247926_11_36_3_4, sectorPos=(11, 36, 3), type=3, seed=-3529445318389979827, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-251.2003, 259.7835, -127.59725), minPos=(-4, -4, -5), maxPos=(3, 3, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_2, sectorPos=(11, 36, 3), type=3, seed=6075141803062040085, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(-363.9849, -306.10913, 306.95834), minPos=(-3, -5, -6), maxPos=(2, 4, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_4, sectorPos=(11, 36, 3), type=3, seed=-3529445318389979827, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-252.10196, 284.7759, -118.6858), minPos=(-4, -4, -5), maxPos=(3, 3, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480633_11_36_3_0, sectorPos=(11, 36, 3), type=3, seed=3344740543496289865, lastModifier=, spawner=, realName=Asteroid (rich in Rammet, Sertise), touched=false, faction=0, pos=(-264.1125, -177.01012, -156.30392), minPos=(-4, -6, -6), maxPos=(3, 5, 5), creatorID=7], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_6, sectorPos=(11, 36, 3), type=3, seed=3114645748701364969, lastModifier=, spawner=, realName=Asteroid (rich in Parseen, Sapsun), touched=false, faction=0, pos=(308.99567, 355.78857, 345.85458), minPos=(-3, -6, -4), maxPos=(2, 5, 3), creatorID=5], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_3, sectorPos=(11, 36, 3), type=3, seed=-1337967039910269201, lastModifier=, spawner=, realName=Asteroid (rich in Hattel, Hylat), touched=false, faction=0, pos=(242.2374, 308.21988, -108.5834), minPos=(-5, -4, -6), maxPos=(4, 3, 5), creatorID=1], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480633_11_36_3_1, sectorPos=(11, 36, 3), type=3, seed=-111421776669247164, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(307.07913, -125.79466, -20.128979), minPos=(-3, -6, -5), maxPos=(2, 5, 4), creatorID=3], 0]
RETURN: [SERVER, DatabaseEntry [uid=ENTITY_FLOATINGROCK_1468029480634_11_36_3_5, sectorPos=(11, 36, 3), type=3, seed=-5280258136270619386, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-314.47284, 176.36885, 323.39764), minPos=(-3, -6, -6), maxPos=(2, 5, 5), creatorID=3], 0]
RETURN: [SERVER, SECTOR INFO: Sector[3774](11, 36, 3); Protected: false; Peace: false; Seed: 0; Type: ASTEROID;, 0]
RETURN: [SERVER, END; Admin command execution ended, 0]

-validated-
-confirmed-
same thing when i do reimport it.
maybe for some reason its not possible to export that stuff ?

putting in queue .. maybe it makes sense if you know how the code works

SmilingDemon changed the task status from Open to In Queue (Game).Jul 9 2016, 2:41 PM

Restricted Application edited projects, added Game Development; removed Issue Navigation. · View Herald TranscriptJul 9 2016, 2:41 PM

SmilingDemon moved this task from Unclassed to Issue affecting current release on the Starmade board.Jul 9 2016, 2:41 PM

SmilingDemon renamed this task from Loading sector causes mass timeouts to Loading sector causes mass timeouts with colliding asteroids.Aug 3 2016, 11:31 AM

SmilingDemon mentioned this in T1557: asteroid generation not working.Aug 3 2016, 11:51 AM

Some more log files if it helps. We have an entire region on our server afflicted by this issue since the chunk update. The only solution I've found is to delete every offending sector but I keep finding more.

8-5-10.09.log.txt983 KBDownload

8-5-4.52.log.txt1 MBDownload

Edit: I moved one of these sectors to an isolated region of space and the sector loads fine.

and what server is that ?

its running out of memory .. i guess because of thos collisions ?

[2016-08-05 14:05:01] java.lang.OutOfMemoryError: GC overhead limit exceeded
[2016-08-05 14:05:01] 	at org.schema.game.common.data.world.SegmentData.<init>(SourceFile:151)
[2016-08-05 14:05:02] 	at obfuscated.Vz.a(SourceFile:90)
[2016-08-05 14:05:02] 	at obfuscated.VA.a(SourceFile:283)
[2016-08-05 14:05:02] 	at obfuscated.aqI.a(SourceFile:89)
[2016-08-05 14:05:02] 	at obfuscated.aqI.a(SourceFile:195)
[2016-08-05 14:05:02] 	at obfuscated.aqI.a(SourceFile:119)
[2016-08-05 14:05:02] 	at org.schema.game.server.controller.GameServerController.a(SourceFile:2252)
[2016-08-05 14:05:02] 	at obfuscated.aqM.run(SourceFile:68)
[2016-08-05 14:05:02] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[2016-08-05 14:05:02] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[2016-08-05 14:05:02] 	at java.lang.Thread.run(Thread.java:745)

It's the star squadron server. The problem starts here and it just keeps throwing out these errors until the server dies.

[2016-08-05 08:49:11] [SERVER][CUBECUBE] COL: 853 ms; !DistiTests[AABBvsAABB]: 12!; ); on Asteroid(1742)sec[1735]: ANonECOUNT 19; ATOTAl 204339; Asteroid(1740)sec[1735]: BNonECOUNT 31; BTOTAl 592694
[2016-08-05 08:49:11] [CC]INFO#0: {RigBExOrig@1010448460Asteroid(1742)sec[1735];COLSHAPE:[CubesShape|SER Asteroid(1742)sec[1735]];AT(97.56031, 306.10034, -241.25708)(SID: Sector[1735](-11, -7, 99))}: (97.56031, 306.10034, -241.25708); {RigBExOrig@306586744Asteroid(1740)sec[1735];COLSHAPE:[CubesShape|SER Asteroid(1740)sec[1735]];AT(191.1615, 224.15498, -166.35493)(SID: Sector[1735](-11, -7, 99))}: (191.1615, 224.15498, -166.35493) UPDATE#: -9123
[2016-08-05 08:49:11] [CC]INFO#1: AABB-A: [ (3.5603104, 168.10034, -290.25708) | (173.5603, 287.10034, -191.25708) ]; AABB-B: [ (46.1615, 175.15498, -310.35492) | (176.1615, 273.15497, -117.354935) ]; Intersection for A [(-64, -128, -64); (96, 0, 96)]; B [(-160, -64, -128); (0, 96, 0)]
[2016-08-05 08:49:11] [CC]INFO#2: [(160, 128, 160)(160, 160, 128)]; ItA: 0 / 0; ItB 0 / 0
[2016-08-05 08:49:11] [CC]INFO#3: TotalA: 204339; TotalB 592694
[2016-08-05 08:49:11] [CC]INFO#4: BufA: 1; BufB: 1
[2016-08-05 08:49:11] [CC]INFO#5: overlappingSingleBlockAABBs: 255396; handle: 12/12 of MAX 10000; DistiT: 852; of that: Sweep: 0msNarrT: 0; OctT: 0retrT(0) aabbT(0); asmAT: 0 ms; asmBT: 0 ms; TotalHandleT(): 853 ms;;; leafCalls#(4352)
[2016-08-05 08:49:11] Sector[1735](-11, -7, 99) Narrowphase of Sector[1735](-11, -7, 99) took: 855
[2016-08-05 08:49:11] Sector[1735](-11, -7, 99) LISTING OBJECTS:
[2016-08-05 08:49:11] 0# OBJECT: {RigBExOrig@990137255([CCS|SER Asteroid(1744)sec[1735]])}
[2016-08-05 08:49:11] 1# OBJECT: {RigBExOrig@386064182([CCS|SER Asteroid(1738)sec[1735]])}
[2016-08-05 08:49:11] 2# OBJECT: {RigBExOrig@1032609287([CCS|SER Asteroid(1743)sec[1735]])}
[2016-08-05 08:49:11] 3# OBJECT: {RigBExOrig@1248935202([CCS|SER Asteroid(1746)sec[1735]])}
[2016-08-05 08:49:11] 4# OBJECT: {RigBExOrig@1348774236([CCS|SER Asteroid(1745)sec[1735](!)])}
[2016-08-05 08:49:11] 5# OBJECT: {RigBExOrig@11206720([CCS|SER Asteroid(1747)sec[1735]])}
[2016-08-05 08:49:11] 6# OBJECT: {RigBExOrig@1520265751([CCS|SER Asteroid(1749)sec[1735]])}
[2016-08-05 08:49:11] 7# OBJECT: {RigBExOrig@346045051([CCS|SER Asteroid(1736)sec[1735]])}
[2016-08-05 08:49:11] 8# OBJECT: {RigBExOrig@1010448460([CCS|SER Asteroid(1742)sec[1735]])}
[2016-08-05 08:49:11] 9# OBJECT: {RigBExOrig@593456081([CCS|SER Asteroid(1739)sec[1735]])}
[2016-08-05 08:49:11] 10# OBJECT: {RigBExOrig@306586744([CCS|SER Asteroid(1740)sec[1735]])}
[2016-08-05 08:49:11] 11# OBJECT: {RigBExOrig@1302296699([CCS|SER Asteroid(1748)sec[1735]])}
[2016-08-05 08:49:11] 12# OBJECT: {RigBExOrig@547289869([CCS|SER Asteroid(1741)sec[1735]])}
[2016-08-05 08:49:11] 13# OBJECT: {RigBExOrig@628368182([CCS|SER Asteroid(1737)sec[1735]])}
[2016-08-05 08:49:11] [CC] POSSIBLE STUCK (timeframe: 2.5 secs): Asteroid(1740)sec[1735] <-> Asteroid(1742)sec[1735]: from (14.672432, -63.970657, -33.98358) to (30, -47, -17); existing surround: 7

Asteroid spawning/respawning appears to be the cause behind GenX's most recent rash of crashing as well. Unknown if @bobbybighoof has respawn enabled/disabled, but their logs show a distinct pattern of asteroid AABB checks, immediately followed by a ping/pong death spiral.

erthparadine mentioned this in T1409: Respawning asteroids causes server lag.Aug 6 2016, 10:00 PM

Merged tasks in ... all contain asteroids with same seed , spawned in the nearly same place ... with two uid numbers ... and causing problems

Asteroid related lagoffs are still happening, latest release, roid respawning is still disabled:

Aug 18 16:27:47 stars SMPrd: [CC] Server(0) Objects detected stuck --- applying outforce: Asteroid(1818)sec[1813] from Asteroid(1815)sec[1813] DIR: (0.05979049, -0.004917397, 0.9981988)
Aug 18 16:27:47 stars SMPrd: [CC] Server(0) Objects detected stuck --- applying outforce: Asteroid(1815)sec[1813] from Asteroid(1818)sec[1813] DIR: (-0.05979049, 0.004917397, -0.9981988)
Aug 18 16:27:47 stars SMPrd: Sector[1813](3, 3, -2044) Narrowphase of Sector[1813](3, 3, -2044) took: 1430
Aug 18 16:27:47 stars SMPrd: Sector[1813](3, 3, -2044) LISTING OBJECTS:
Aug 18 16:27:47 stars SMPrd: 0# OBJECT: {RigBExOrig@97675420([CCS|SER Asteroid(1814)sec[1813](!)])}
Aug 18 16:27:47 stars SMPrd: 1# OBJECT: {RigBExOrig@1266898186([CCS|SER Asteroid(1816)sec[1813]])}
Aug 18 16:27:47 stars SMPrd: 2# OBJECT: {RigBExOrig@1879730758([CCS|SER Asteroid(1817)sec[1813]])}
Aug 18 16:27:47 stars SMPrd: 3# OBJECT: {RigBExOrig@1902021112([CCS|SER Asteroid(1818)sec[1813]])}
Aug 18 16:27:47 stars SMPrd: 4# OBJECT: {RigBExOrig@1742641607([CCS|SER Asteroid(1815)sec[1813]])}
Aug 18 16:27:47 stars SMPrd: [UNIVERSE] WARNING: Sector UPDATE took 1447; sectors updated: 81
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] SENDING SYSTEM BACK TO CLIENT: -1342, -1262, -2045
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] SENDING SYSTEM BACK TO CLIENT: -1358, -1262, -2045
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] SENDING SYSTEM BACK TO CLIENT: -1374, -1262, -2045
Aug 18 16:27:47 stars SMPrd: [SERVER][UPDATE] WARNING: UNIVERSE update took 1447
Aug 18 16:27:47 stars SMPrd: Server(0) [GRAVITY] PlayerCharacter[(ENTITY_PLAYERCHARACTER_PUNISHER77)(1481)] RECEIVED REMOTE GRAVITY: 1482 --- (0.0, 0.0, 0.0)
Aug 18 16:27:47 stars SMPrd: [GRAVITY] GRAVITY DELAYED FOR PlayerCharacter[(ENTITY_PLAYERCHARACTER_PUNISHER77)(1481)]. source not found: 1482
Aug 18 16:27:47 stars SMPrd: [SimpleTransformable][GRAVITY] Server(0) sending gravity update GRAV[NULL; (0.0, 0.0, 0.0)]
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] REQUESTING SYSTEM (-86, -80, -128); exists in DB: false; TIME: 0ms: GalaxyRequestAndAwnser [ownerUID=null, factionUID=0, secX=-1374, secY=-1278, secZ=-2045, networkObjectOnServer=NetworkObject(NetworkClientChannel; 0)]
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] REQUESTING SYSTEM (-86, -81, -128); exists in DB: false; TIME: 1ms: GalaxyRequestAndAwnser [ownerUID=null, factionUID=0, secX=-1374, secY=-1294, secZ=-2045, networkObjectOnServer=NetworkObject(NetworkClientChannel; 0)]
Aug 18 16:27:47 stars SMPrd: [DATABASE][SYSTEMS] NO SYSTEM ENTRY FOUND FOR -1 FOR (-73, -79, -128)
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] REQUESTING SYSTEM (-86, -82, -128); exists in DB: false; TIME: 0ms: GalaxyRequestAndAwnser [ownerUID=null, factionUID=0, secX=-1374, secY=-1310, secZ=-2045, networkObjectOnServer=NetworkObject(NetworkClientChannel; 0)]
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] REQUESTING SYSTEM (-86, -83, -128); exists in DB: false; TIME: 0ms: GalaxyRequestAndAwnser [ownerUID=null, factionUID=0, secX=-1374, secY=-1326, secZ=-2045, networkObjectOnServer=NetworkObject(NetworkClientChannel; 0)]
Aug 18 16:27:47 stars SMPrd: [SERVER][GALAXY] REQUESTING SYSTEM (-86, -84, -128); exists in DB: false; TIME: 0ms: GalaxyRequestAndAwnser [ownerUID=null, factionUID=0, secX=-1374, secY=-1342, secZ=-2045, networkObjectOnServer=NetworkObject(NetworkClientChannel; 0)]
Aug 18 16:27:47 stars SMPrd: [DATABASE][SYSTEMS] NO SYSTEM ENTRY FOUND FOR -1 FOR (-74, -79, -128)
Aug 18 16:27:48 stars SMPrd: [CC] Server(0) Objects detected stuck --- applying outforce: Asteroid(1818)sec[1813] from Asteroid(1815)sec[1813] DIR: (0.0634285, -0.007267188, 0.9979599)
Aug 18 16:27:48 stars SMPrd: [CC] Server(0) Objects detected stuck --- applying outforce: Asteroid(1815)sec[1813] from Asteroid(1818)sec[1813] DIR: (-0.0634285, 0.007267188, -0.9979599)
Aug 18 16:27:48 stars SMPrd: Sector[1813](3, 3, -2044) Narrowphase of Sector[1813](3, 3, -2044) took: 1050
Aug 18 16:27:48 stars SMPrd: Sector[1813](3, 3, -2044) LISTING OBJECTS:
Aug 18 16:27:48 stars SMPrd: 0# OBJECT: {RigBExOrig@97675420([CCS|SER Asteroid(1814)sec[1813](!)])}
Aug 18 16:27:48 stars SMPrd: 1# OBJECT: {RigBExOrig@1266898186([CCS|SER Asteroid(1816)sec[1813]])}
Aug 18 16:27:48 stars SMPrd: 2# OBJECT: {RigBExOrig@1879730758([CCS|SER Asteroid(1817)sec[1813]])}
Aug 18 16:27:48 stars SMPrd: 3# OBJECT: {RigBExOrig@1902021112([CCS|SER Asteroid(1818)sec[1813]])}
Aug 18 16:27:48 stars SMPrd: 4# OBJECT: {RigBExOrig@1742641607([CCS|SER Asteroid(1815)sec[1813]])}
Aug 18 16:27:48 stars SMPrd: [CC] POSSIBLE STUCK (timeframe: 2.5 secs): Asteroid(1816)sec[1813] <-> Asteroid(1815)sec[1813]: from (-122.505165, -36.24547, -50.10724) to (-106, -20, -34); existing surround: 7
Aug 18 16:27:50 stars SMPrd: [SERVERPROCESSOR][WARNING} PING timeout warning. resending ping to RegisteredClient: PUNISHER77 (5) [Colesr]connected: true Retries left: 12; socket connected: true; socket closed: false; inputShutdown: false; outputShutdown: false; ProcessorID: 461
Aug 18 16:27:50 stars SMPrd: [SERVERPROCESSOR][WARNING} PING has been resent to RegisteredClient: PUNISHER77 (5) [Colesr]connected: true
Aug 18 16:27:50 stars SMPrd: [SERVERPROCESSOR][WARNING} PING timeout warning. resending ping to RegisteredClient: ballog (6) [ballog]connected: true Retries left: 12; socket connected: true; socket closed: false; inputShutdown: false; outputShutdown: false; ProcessorID: 486
Aug 18 16:27:50 stars SMPrd: [SERVERPROCESSOR][WARNING} PING has been resent to RegisteredClient: ballog (6) [ballog]connected: true
Aug 18 16:27:51 stars SMPrd: RETRY STATUS: Retries: 11; waiting for pong true (1471537671038/1471537680038); ProcessorID: 461
Aug 18 16:27:51 stars SMPrd: RETRY STATUS: Retries: 11; waiting for pong true (1471537671333/1471537680333); ProcessorID: 486
Aug 18 16:27:52 stars SMPrd: RETRY STATUS: Retries: 11; waiting for pong true (1471537672038/1471537680038); ProcessorID: 461
Aug 18 16:27:52 stars SMPrd: RETRY STATUS: Retries: 11; waiting for pong true (1471537672333/1471537680333); ProcessorID: 486
Aug 18 16:27:53 stars SMPrd: RETRY STATUS: Retries: 11; waiting for pong true (1471537673039/1471537680038); ProcessorID: 461

lancake merged a task: T1860: Asteroid regeneration sometimes generates duplicate asteroids in the same place.Aug 28 2016, 6:20 PM

lancake added a subscriber: Barteks2x.

I'm seeing this on a fresh install of 0.199.253.
Previously we had ASTEROIDS_ENABLE_DYNAMIC_PHYSICS = false, so it may have gone unnoticed if there were no collision checks happening.

Steps to reproduce:

clean install of 0.199.153
move over server-database/world/.seed from previous server install (should be irrelevant)
ASTEROIDS_ENABLE_DYNAMIC_PHYSICS = true
ASTEROID_RADIUS_MAX = 64
ASTEROID_SECTOR_REPLENISH_TIME_SEC = 2500000
spawn a player, get /sector_info of surrounding sectors
move away to unload sector, move back, get /sector_info again
repeat last until duplicate asteroids appear; maybe try different sectors

Duplicate asteroids do get generated frequently but not always, but if so, then after repeated visits to this sector, often there are even more than two with identical seed.

Needless to say this causes constant collisions. Setting ASTEROIDS_ENABLE_DYNAMIC_PHYSICS = false obviously prevents those collisions from happening and is probably the cause for this issue to go unnoticed in many cases.

.seed8 BDownload

A bit more data:

What I find noteworthy is how there are consecutive unique asteroids generated within milliseconds (assuming the last three digits do represent milliseconds) of each other, and then obviously a later run that is responsible for the duplicates, with another unique asteroid generated in that same run.
Also worth noting is how the milliseconds(?) part just seems to continue, despite the seconds indicating almost three days between the two generations (the missing xxxxxxxxxx623 may have been deleted or mined out, or it might have been skipped, sadly I'm unable to trace back what exactly happened to it).

output of sector_info 4 -7 9, sorted by uid, (D) denotes duplicate seeds:

    1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476620882619_4_-7_9_0, type=Asteroid, seed=6753287484690755302, lastModifier=, spawner=, realName=Asteroid (rich in Mattise, Jisper), touched=false, faction=0, pos=(-144.486, -462.31848, 287.78473), minPos=(-3, -4, -5), maxPos=(2, 3, 4), creatorID=2, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
    1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476620882620_4_-7_9_2, type=Asteroid, seed=-679781881568873180, lastModifier=, spawner=, realName=Asteroid (rich in Varat, Zercaner), touched=false, faction=0, pos=(329.72818, 378.66257, 630.7423), minPos=(-4, -5, -4), maxPos=(3, 4, 3), creatorID=0, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
    1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476620882621_4_-7_9_3, type=Asteroid, seed=5513724535392888612, lastModifier=, spawner=, realName=Asteroid (rich in Bastyn, Fertikeen), touched=false, faction=0, pos=(-48.22148, 207.86165, -429.93045), minPos=(-3, -3, -4), maxPos=(2, 2, 3), creatorID=4, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
    1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476620882622_4_-7_9_4, type=Asteroid, seed=-3960624192368313824, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=true, faction=0, pos=(-142.24896, 260.4069, 292.51996), minPos=(-4, -4, -4), maxPos=(3, 3, 3), creatorID=3, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
(D) 1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476866956624_4_-7_9_0, type=Asteroid, seed=6753287484690755302, lastModifier=, spawner=, realName=Asteroid (rich in Mattise, Jisper), touched=false, faction=0, pos=(124.83521, -135.09326, -103.60916), minPos=(-3, -4, -5), maxPos=(2, 3, 4), creatorID=2, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
    1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476866956625_4_-7_9_1, type=Asteroid, seed=-5844930534087936898, lastModifier=, spawner=, realName=Asteroid (rich in Bastyn, Fertikeen), touched=false, faction=0, pos=(248.0, 345.0, -329.0), minPos=(-4, -5, -4), maxPos=(3, 4, 3), creatorID=4, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
(D) 1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476866956626_4_-7_9_2, type=Asteroid, seed=-679781881568873180, lastModifier=, spawner=, realName=Asteroid (rich in Varat, Zercaner), touched=false, faction=0, pos=(357.6226, 297.34656, -102.21972), minPos=(-4, -5, -4), maxPos=(3, 4, 3), creatorID=0, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
(D) 1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476866956627_4_-7_9_3, type=Asteroid, seed=5513724535392888612, lastModifier=, spawner=, realName=Asteroid (rich in Bastyn, Fertikeen), touched=false, faction=0, pos=(-552.6098, 337.29117, -206.69751), minPos=(-3, -3, -4), maxPos=(2, 2, 3), creatorID=4, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true
(D) 1477312294 [SEND][SERVERMESSAGE] LoadedEntity [uid=ENTITY_FLOATINGROCK_1476866956628_4_-7_9_4, type=Asteroid, seed=-3960624192368313824, lastModifier=, spawner=, realName=Asteroid (rich in Nocx, Macet), touched=false, faction=0, pos=(-552.87317, 241.01373, 204.60799), minPos=(-4, -4, -4), maxPos=(3, 3, 3), creatorID=3, emptyObject=false] to RegisteredClient: Valck (1) [Valck]connected: true

I've seen this too Valck. We just gave up on seeing this get attention anytime soon, and wrote a ~15 line "supervising" bash script that monitors logfiles for the flood of collsions and tp's colliding asteroids into other areas of the same sector. With this, I've had nearly 100 large asteroids clustered in just one sector, and it no longer risks crashing a server.

schema added a commit: Restricted Diffusion Commit.Mar 10 2017, 2:59 AM

schema changed the task status from In Queue (Game) to Resolved by committing Restricted Diffusion Commit.

Restricted Application edited projects, added Quality Assurance; removed Game Development. · View Herald TranscriptMar 10 2017, 2:59 AM

Implemented abnormal collision handling. The system will warp asteroids to a save spot. The provided sector is now solved in around 15 seconds without getting stuck very much (there is a 5 sec "timeout" which is started to count down when the object is involved in an abnormal, aka overlapping, collision

Restricted Application added a project: Universe. · View Herald TranscriptMar 10 2017, 6:11 PM

AndyP edited projects, added Physics; removed Universe.Mar 15 2017, 4:15 PM

AndyP changed Category from Universe to Physics.

AndyP moved this task from Backlog / Unclassed to Alpha on the Physics board.Mar 15 2017, 4:19 PM

-QA Testing-

Partial fix.

logstarmade.0.log3 MBDownload

You can reproduce this by importing and loading the sector provided in the description.

lancake moved this task from Confirmed fix to Coordinate multiplayer test on the Quality Assurance board.Mar 27 2017, 1:59 PM

lancake changed the task status from Resolved to In Queue.

Restricted Application edited projects, added Game Development, QA-Return; removed Quality Assurance. · View Herald TranscriptMar 27 2017, 1:59 PM

lancake edited Tester information (Internal use only). (Show Details)Mar 27 2017, 2:00 PM

lancake changed Last tested (version) from 0.198.419 (DEV) to 0.199.491.

lancake set First occurrence (version) to 0.198.419.

I don't know how much this helps or not, but our external script approach is pretty basic, and there's no asteroid boomeranging as suggested in @lancake message above.

The script triggers on this particular regex:

'^.*Narrowphase of Sector\[[0-9]+\]\(([-0-9]+), ([-0-9]+), ([-0-9]+)\) took: (.*)'

Since narrowphase messages have a tendency to come in clusters, sometimes multiple entries per second, we use a lockfile to prevent multiple cleanup routines from firing at the same time on the same sector (also notice there's a 1 second sleep after each move).

Here's the heart of our script:

# Only attempt cleanup if lag greater than 30ms
if [ "$laggingTime" -ge "35" ]; then
  # These two sed strings will return only the UIDs of asteroids
  for uid in `sed 's/RETURN: \[SERVER, LoadedEntity.*\[\([^]]*\)\].*/\1/g;tx;d;:x' /dev/shm/sectorLagging.info |sed 's/^uid=\(.*\), type=Asteroid.*/\1/g;;tx;d;:x'`; do
    echo "Nudging laggy sector $laggingSectorX $laggingSectorY $laggingSectorZ of $uid" | awk '{print "[PAFKA] "$0}' | /usr/bin/logger -t SMPrd
    roidTPX=`echo "$(shuf -i 1-7000 -n 1)-3500" |bc`
    roidTPY=`echo "$(shuf -i 1-7000 -n 1)-3500" |bc`
    roidTPZ=`echo "$(shuf -i 1-7000 -n 1)-3500" |bc`
    serverCommand /teleport_uid_to \"$uid\" $roidTPX $roidTPY $roidTPZ |& awk '{print "[PAFKA] "$0}' | /usr/bin/logger -t SMPrd
    # pause after moves, to give the server time to catchup
    sleep 1
  done
fi

lancake moved this task from Issue affecting current release to Archived on the Starmade board.Mar 29 2017, 1:21 PM

warp was applied while in physics process, which in turn overwrote the fix

Restricted Application edited projects, added Quality Assurance; removed QA-Return, Game Development. · View Herald TranscriptMar 31 2017, 1:28 PM

Antikristianos added a subscriber: Antikristianos.Mar 18 2018, 10:32 PM

This Problem is back again in v0.200.334
as soon as a player came close enough to more than one sector with these Duplicate Asteroids in the same place our server crashed and had to be restarted manually.

Hello, I am attempting to run a new Server and am new to all this...

We seem to be having this problem, is there a workaround?...

or is this happening everywhere?

Starmade | Loading sector causes mass timeouts with colliding asteroidsResolved, needs quality check / confirm fix, UrgentPublicActions

Description

Details

Related Objects

Event Timeline

Starmade | Loading sector causes mass timeouts with colliding asteroids
Resolved, needs quality check / confirm fix, UrgentPublic
Actions