Fixed Unable to warp to new star systems

Common Intermittent Issue on dedicated server.
Mode: Survival
Mode: Dedicated Server

SERVER NAME: Broken Eden
SEED-ID: 1215444

If applicable:
MODIFIED PLAYFIELDS: Yes (Project Eden)

Reproducibility: Sometimes
Severity: Major

Type: Playfield Server

Summary: As of 12.2.1 hotfix, players are unable to warp to previously undiscovered stars. All star types appear to be effected.
The warp animation and loading screen appears but the player is booted back to their last playfield and the pentaxid is consumed.

Description:
Server PF timeout is set to 2000 but that amount of time does not pass before the player is booted back to their previous playfield. The logfile shows a timeout but it does not appear to be a timeout based on how quickly this happens.
This issue did happen before 12.2.1 but as of that hotfix it is now become even more prevalent, this is possibly related to more players starting to explore however so could be a red herring.

We are running the Project Eden scenario on a Windows Server 2016 dedicated server with full EAH.
Savegame started in version 12.2

This is a major bug preventing players from exploring beyond currently explored solar systems.

Steps to Reproduce: Warp to a new star system you have not previously been to.

 

Here is a excerpt of the above log showing SQL errors and the almost instantaneous PFServer time out - Dispite the PF Timeout being set to 2000:

10-13:48:29.609 09_48 -LOG- Client CId=7, EId=15001, 76561198051236855/=/'Johnny Jay Appleseed' changes playfield to Mola [Sun Back]
10-13:48:29.609 09_48 -LOG- Changing to playfield 'Mola [Sun Back]' needs new playfield server, queueing now
10-13:48:29.610 09_48 -WRN- Unloading pf 'Mola [Sun Back]' of pf server (PID 3376) due to a load timeout (fail count: 1)
10-13:48:29.610 09_48 -LOG- Requesting pf server with PID 3376 to unload playfield Mola [Sun Back]
10-13:48:33.994 09_48 -LOG- INFO: Uptime=00h40m heap= 500MB fps= 40 players=12 pfs=r0/i4/a8 nwqueue=Net:1/12| 0 B| 27 B| 0 B| 6.5 KB| ticks=11473806
10-13:48:39.817 09_48 -LOG- Requesting pf server with PID 3376 to load playfield Mola [Sun Back]
10-13:48:40.118 09_48 -LOG- Playfield server (PID 3376) loaded playfield 'Mola [Sun Back]' in 0.3 sec
10-13:48:40.118 09_48 -LOG- Requesting feedback for playfield change for client 7: Got playfield server for 'Mola [Sun Back]'
10-13:48:40.168 09_48 -LOG- Feedback for client CId=7, EId=15001, 76561198051236855/=/'Johnny Jay Appleseed' pos=(0.0, 0.0, -12000.0) within=762052 received from 'Mola [Sun Back]'. Changing worlds now...
10-13:48:40.168 09_48 -LOG- Disconnecting client CId=7, EId=15001, 76561198051236855/=/'Johnny Jay Appleseed' from 'Kessel Prime IV Sector' - now empty => enqueued for delayed unload
10-13:48:40.168 09_48 -LOG- Connecting CId=7, EId=15001, 76561198051236855/=/'Johnny Jay Appleseed' to 'Mola [Sun Back]'
10-13:48:40.218 09_48 -ERR- UPDATE Entities SET name = @name, pfid = (SELECT pfid FROM Playfields pf WHERE pf.name = @pfname), facgroup = @facgroup, facid = @facid, posx = @posx, posy = @posy, posz = @posz, rotx = @rotx, roty = @roty, rotz = @rotz, health = @health, isproxy = @proxy, dockedto = @dockedto WHERE entityid = @entityid
10-13:48:40.218 09_48 -ERR- Parameters:
10-13:48:40.218 09_48 -ERR- 0=SFS-LineBacker-refit
10-13:48:40.218 09_48 -ERR- 1=Mola [Sun Back]
10-13:48:40.218 09_48 -ERR- 2=0
10-13:48:40.218 09_48 -ERR- 3=101
10-13:48:40.218 09_48 -ERR- 4=0
10-13:48:40.218 09_48 -ERR- 5=0
10-13:48:40.218 09_48 -ERR- 6=-12000
10-13:48:40.218 09_48 -ERR- 7=0
10-13:48:40.218 09_48 -ERR- 8=0
10-13:48:40.218 09_48 -ERR- 9=0
10-13:48:40.218 09_48 -ERR- 10=20000
10-13:48:40.218 09_48 -ERR- 11=True
10-13:48:40.218 09_48 -ERR- 12=762052
10-13:48:40.218 09_48 -ERR- 13=
10-13:48:40.220 09_48 -EXC- code = Constraint (19), message = System.Data.SQLite.SQLiteException (0x800027AF): constraint failed
NOT NULL constraint failed: Entities.pfid
at System.Data.SQLite.SQLite3.Reset (System.Data.SQLite.SQLiteStatement stmt) [0x00088] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLite3.Step (System.Data.SQLite.SQLiteStatement stmt) [0x0006e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader.NextResult () [0x00174] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader..ctor (System.Data.SQLite.SQLiteCommand cmd, System.Data.CommandBehavior behave) [0x0008e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at (wrapper remoting-invoke-with-check) System.Data.SQLite.SQLiteDataReader..ctor(System.Data.SQLite.SQLiteCommand,System.Data.CommandBehavior)
at System.Data.SQLite.SQLiteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x0000c] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery (System.Data.CommandBehavior behavior) [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery () [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at Assembly-CSharp.ComponentInvoker.ViewPartition (Assembly-CSharp.ContextOptions+Outline ) [0x0011d] in <0ce5631c6d164269905ad1d036b92ecd>:0
10-13:48:41.871 09_48 -ERR- INSERT INTO ChangedPlayfields (type, entityId, attentityid, frompfid, topfid, fromposx, fromposy, fromposz, toposx, toposy, toposz, aspassenger, spawnat, gametime) VALUES ( @type, @entityid, @attentityid, (SELECT pfid FROM Playfields pf WHERE pf.name = @frompfname), (SELECT pfid FROM Playfields pf WHERE pf.name = @topfname), @fromposx, @fromposy, @fromposz, @toposx, @toposy, @toposz, @aspassenger, @spawnat, @ticks )
10-13:48:41.871 09_48 -ERR- Parameters:
10-13:48:41.871 09_48 -ERR- 0=8
10-13:48:41.871 09_48 -ERR- 1=15001
10-13:48:41.871 09_48 -ERR- 2=762052
10-13:48:41.871 09_48 -ERR- 3=Kessel Prime IV Sector
10-13:48:41.871 09_48 -ERR- 4=Mola [Sun Back]
10-13:48:41.871 09_48 -ERR- 5=1
10-13:48:41.871 09_48 -ERR- 6=4
10-13:48:41.871 09_48 -ERR- 7=-12031
10-13:48:41.871 09_48 -ERR- 8=0
10-13:48:41.871 09_48 -ERR- 9=0
10-13:48:41.871 09_48 -ERR- 10=-12000
10-13:48:41.871 09_48 -ERR- 11=False
10-13:48:41.871 09_48 -ERR- 12=
10-13:48:41.871 09_48 -ERR- 13=11473957
10-13:48:41.871 09_48 -EXC- code = Constraint (19), message = System.Data.SQLite.SQLiteException (0x800027AF): constraint failed
NOT NULL constraint failed: ChangedPlayfields.topfid
at System.Data.SQLite.SQLite3.Reset (System.Data.SQLite.SQLiteStatement stmt) [0x00088] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLite3.Step (System.Data.SQLite.SQLiteStatement stmt) [0x0006e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader.NextResult () [0x00174] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader..ctor (System.Data.SQLite.SQLiteCommand cmd, System.Data.CommandBehavior behave) [0x0008e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at (wrapper remoting-invoke-with-check) System.Data.SQLite.SQLiteDataReader..ctor(System.Data.SQLite.SQLiteCommand,System.Data.CommandBehavior)
at System.Data.SQLite.SQLiteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x0000c] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery (System.Data.CommandBehavior behavior) [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery () [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at Assembly-CSharp.ComponentInvoker.ViewPartition (Assembly-CSharp.ContextOptions+Outline ) [0x0011d] in <0ce5631c6d164269905ad1d036b92ecd>:0
10-13:49:01.640 09_49 -LOG- Requesting pf server with PID 4116 to unload playfield Kessel Prime IV Sector
10-13:49:01.715 09_49 -LOG- PfServer (PID 4116) unloaded 'Kessel Prime IV Sector'
10-13:49:34.017 09_49 -LOG- INFO: Uptime=00h41m heap= 497MB fps= 40 players=12 pfs=r0/i5/a7 nwqueue=Net:0/12 ticks=11475006
10-13:49:40.219 09_49 -ERR- INSERT INTO PlayerPosHistory (entityid, pfid, posx, posy, posz, attentityid, gametime) VALUES (@entityid, (SELECT pfid FROM Playfields WHERE name = @pfname), @posx, @posy, @posz, @attentityid, @gametime)
10-13:49:40.219 09_49 -ERR- Parameters:
10-13:49:40.219 09_49 -ERR- 0=15001
10-13:49:40.219 09_49 -ERR- 1=Mola [Sun Back]
10-13:49:40.219 09_49 -ERR- 2=311
10-13:49:40.219 09_49 -ERR- 3=1290
10-13:49:40.219 09_49 -ERR- 4=-9673
10-13:49:40.219 09_49 -ERR- 5=762052
10-13:49:40.219 09_49 -ERR- 6=11475129
10-13:49:40.220 09_49 -EXC- code = Constraint (19), message = System.Data.SQLite.SQLiteException (0x800027AF): constraint failed
NOT NULL constraint failed: PlayerPosHistory.pfid
at System.Data.SQLite.SQLite3.Reset (System.Data.SQLite.SQLiteStatement stmt) [0x00088] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLite3.Step (System.Data.SQLite.SQLiteStatement stmt) [0x0006e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader.NextResult () [0x00174] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteDataReader..ctor (System.Data.SQLite.SQLiteCommand cmd, System.Data.CommandBehavior behave) [0x0008e] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at (wrapper remoting-invoke-with-check) System.Data.SQLite.SQLiteDataReader..ctor(System.Data.SQLite.SQLiteCommand,System.Data.CommandBehavior)
at System.Data.SQLite.SQLiteCommand.ExecuteReader (System.Data.CommandBehavior behavior) [0x0000c] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery (System.Data.CommandBehavior behavior) [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at System.Data.SQLite.SQLiteCommand.ExecuteNonQuery () [0x00006] in <d52f09e2aa2f4a7593c588778ba249ea>:0
at Assembly-CSharp.ComponentInvoker.ViewPartition (Assembly-CSharp.ContextOptions+Outline ) [0x0011d] in <0ce5631c6d164269905ad1d036b92ecd>:0
10-13:49:54.607 09_49 -LOG- Generating solar system Rangikath/(37900000, 4300000, -119700000) in C:\EmpyrionBrokenEden-Live\DedicatedServer/../Saves/Games/BrokenEden_12.2/Sectors
NullReferenceException: Object reference not set to an instance of an object
at Assembly-CSharp.ConfigLoader.JoinImage (PlayfieldYamlData , DynamicSpacePlayfieldYaml , System.String , System.Int32 , System.Boolean , System.Int32 ) [0x00aa0] in <0ce5631c6d164269905ad1d036b92ecd>:0
at Assembly-CSharp.ConfigLoader.ExtractProject (System.String , System.String , System.String , System.String , System.String , System.Int32 , System.Int32 , PlayfieldYamlData& , System.Collections.Generic.List`1[T] ) [0x000bf] in <0ce5631c6d164269905ad1d036b92ecd>:0
at Assembly-CSharp.ImageSet+ActionOptions.MoveNext () [0x00346] in <0ce5631c6d164269905ad1d036b92ecd>:0
at Assembly-CSharp.ImageSet+FunctionHelper.MoveNext () [0x00545] in <0ce5631c6d164269905ad1d036b92ecd>:0
at Assembly-CSharp.PcitureLoader+ClientEventArgs.MoveNext () [0x000b6] in <0ce5631c6d164269905ad1d036b92ecd>:0
at Assembly-CSharp.PcitureLoader+ActionSettings.MoveNext () [0x00065] in <0ce5631c6d164269905ad1d036b92ecd>:0
at UnityEngine.SetupCoroutine.InvokeMoveNext (System.Collections.IEnumerator enumerator, System.IntPtr returnValueAddress) [0x00027] in <5e1dfb686eb345078a588df96401afcc>:0

(Filename: <0ce5631c6d164269905ad1d036b92ecd> Line: 0)

10-13:50:01.079 09_50 -LOG- NET: Raknet player disconnected CId=1/11695340546335802157

 

I also have this problem.

 

Its an odd one, since re-introducing the bugged drones that we hashed out previously the issue appeared to reduce significantly but now is coming back again, even more players reporting it than before but we have made no changes to the yaml files this time.

Fingers crossed this update resolves the issue, in either case, I will report back asap.

 

Several guys have now retested this issue and so far seems to be resolved. They are now able to warp to systems they were previously unable to.

Thank you for the fix