[9.2.x] Migration from v9.1.9 to 9.2.x - Crash on join

Venopsis commented 3 years ago

User Id: (Not logged user) Version: 0.9.2.1 beta release-146

Steps to Reproduce: Connect to server

Server configuration VPS running Debian 10.7 up-to-date. Hosted using KVM technology. To get running the ecoserver I used Linux Game Server Managers (https://linuxgsm.com/)

Expected behavior: Continue to run normally

Actual behavior: No more able to connect to server. Directly get a crash error message after coming back to main screen:

<size=150%>Connection Failed</size>

Server encountered an exception:

<size=60.00%>Exception: NullReferenceException
Message:Object reference not set to an instance of an object.
Source:Eco.Gameplay

System.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.get_SourceAccount()
   at Eco.Gameplay.Economy.Jobs.RecurringTransferManager.<>c__DisplayClass8_0.<TransfersForUser>b__0(RecurringTransfer x)
   at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext()
   at Eco.Core.Controller.ControllerManager.PackageValue(IMvcNetClient boundClient, Object value, Int32 nameID)
   at Eco.Core.Controller.ControllerManager.PackageProperty(IMvcNetClient boundClient, IController controller, ISyncPropertyInfo propertyInfo)
Outer Exceptions:
Error during packaging property 'IncomeAndExpenses' of 'Eco.Gameplay.Players.User'</size>

Log File:
Initialize engine version: 2019.4.15f1 (fbf367ac14e9)
[Subsystems] Discovering subsystems at path F:/Steam/steamapps/common/Eco/Eco_Data/UnitySubsystems
GfxDevice: creating device client; threaded=1
Direct3D:
    Version:  Direct3D 11.0 [level 11.1]
    Renderer: NVIDIA GeForce GTX 1070 Ti (ID=0x1b82)
    Vendor:   
    VRAM:     8079 MB
    Driver:   27.21.14.6089
D3D11 device created for Microsoft Media Foundation video decoding.
<RI> Initializing input.

<RI> Input initialized.

<RI> Initialized touch support.

UnloadTime: 1.372500 ms
DontDestroyOnLoad only works for root GameObjects or components on root GameObjects. 
(Filename:  Line: 589)

WwiseUnity: Wwise(R) SDK Version 2019.2.5 Build 7349.
UnityEngine.Logger:LogFormat(LogType, String, Object[])
UnityEngine.Debug:LogFormat(String, Object[])
AkWwiseInitializationSettings:InitializeSoundEngine()
AkInitializer:OnEnable()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

WwiseUnity: Setting Plugin DLL path to: F:/Steam/steamapps/common/Eco/Eco_Data\Plugins\x86_64
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
AkCommonPlatformSettings:get_AkInitializationSettings()
AkWwiseInitializationSettings:InitializeSoundEngine()
AkInitializer:OnEnable()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

WwiseUnity: Sound engine initialized successfully.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
AkWwiseInitializationSettings:InitializeSoundEngine()
AkInitializer:OnEnable()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

The referenced script on this Behaviour (Game Object 'Camera') is missing! 
(Filename:  Line: 334)

The referenced script on this Behaviour (Game Object 'Table') is missing! 
(Filename:  Line: 334)

DontDestroyOnLoad only works for root GameObjects or components on root GameObjects.
SteamManager:Awake()

[ line 589] 
(Filename:  Line: 589)

Ambiguous UI component types ignored: SeriesPopupUI,BaseUI,ViewEditorUI,AutoViewUI
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
UI.UIManager:Start()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:49:06.198] LoginSession: connectorHandle=C0
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
VivoxUnity.VivoxDebug:DebugMessage(Object, vx_log_level)
VivoxUnity.Private.<>c__DisplayClass89_0:<BeginLogin>b__0(IAsyncResult)
DG.Tweening.Core.DOSetter`1:Invoke(T)
VivoxUnity.AsyncResult`1:SetComplete(T)
VivoxUnity.<>c__DisplayClass12_0:<BeginGetConnectorHandle>b__0(IAsyncResult)
DG.Tweening.Core.DOSetter`1:Invoke(T)
VivoxUnity.AsyncResult`1:SetComplete(T)
VivoxUnity.VxClient:InstanceOnMainLoopRun(Boolean&)
MessagePump:RunOnce()
MessagePump:RunUntil(LoopDone)
VoiceManager:Update()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:58:33.303] Nat introduction received with token = 40f05175-e4de-4946-86ce-3924db5f4d1d
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
Eco.Shared.Utils.Log:Debug(String, Object[])
Eco.Shared.Networking.NetworkClient:HandleCompleteUnconnectedDataMessage(UdpDataMessage&)
Eco.Shared.Networking.NetworkClient:HandleUnconnectedDataMessage(UdpDataMessage&)
Eco.Shared.Networking.Udp.UdpDataMessageHandler:Invoke(UdpDataMessage&)
Eco.Networking.ENet.ENetUdpPeer:OnRawDataReceived(Address&, IntPtr, Int32, Boolean&)
Eco.Networking.ENet.ENetUdpPeer:Intercept(Event&, Address&, IntPtr, Int32)
ENet.InterceptCallback:Invoke(Event&, Address&, IntPtr, Int32)
ENet.Host:Service(Int32, Event&)
Eco.Networking.ENet.ENetUdpPeer:Service(Int32)
<>c__DisplayClass63_0:<Initialize>b__0()
UnityEngine.DisplaysUpdatedDelegate:Invoke()
System.Action`1:Invoke(T)
System.Threading.ExecutionContext:RunInternal(ExecutionContext, ContextCallback, Object, Boolean)
System.Threading.ExecutionContext:Run(ExecutionContext, ContextCallback, Object)
UnityEngine.DisplaysUpdatedDelegate:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:58:33.339] Connecting to 185.216.25.172:3000...

EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:Log(Object)
Eco.Shared.Utils.Log:WriteLine(LocString)
Eco.Shared.Networking.NetworkClient:ConnectInternal(IPEndPoint)
Eco.Shared.Networking.NetworkClient:ConnectRoundRobin()
Eco.Shared.Networking.NetworkClient:HandleNatIntroductionSuccess(IPEndPoint, String)
Eco.Shared.Networking.NetworkClient:HandleCompleteUnconnectedDataMessage(UdpDataMessage&)
Eco.Shared.Networking.NetworkClient:HandleUnconnectedDataMessage(UdpDataMessage&)
Eco.Shared.Networking.Udp.UdpDataMessageHandler:Invoke(UdpDataMessage&)
Eco.Networking.ENet.ENetUdpPeer:OnRawDataReceived(Address&, IntPtr, Int32, Boolean&)
Eco.Networking.ENet.ENetUdpPeer:Intercept(Event&, Address&, IntPtr, Int32)
ENet.InterceptCallback:Invoke(Event&, Address&, IntPtr, Int32)
ENet.Host:Service(Int32, Event&)
Eco.Networking.ENet.ENetUdpPeer:Service(Int32)
<>c__DisplayClass63_0:<Initialize>b__0()
UnityEngine.DisplaysUpdatedDelegate:Invoke()
System.Action`1:Invoke(T)
System.Threading.ExecutionContext:RunInternal(ExecutionContext, ContextCallback, Object, Boolean)
System.Threading.ExecutionContext:Run(ExecutionContext, ContextCallback, Object)
UnityEngine.DisplaysUpdatedDelegate:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

The referenced script on this Behaviour (Game Object 'LayerViewer') is missing! 
(Filename:  Line: 334)

Unable to open archive file: F:/Steam/steamapps/common/Eco/Eco_Data/StreamingAssets/desc.unity3d 
(Filename:  Line: 584)

Failed to read data for the AssetBundle 'StreamingAssets\desc.unity3d'. 
(Filename:  Line: 449)

[10:58:40.150] Missing sprite in MiscIconMap.
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogError(Object)
ModBundleManager:SetupSprites()
<ReceiveModData>d__47:MoveNext()
UnityEngine.SetupCoroutine:InvokeMoveNext(IEnumerator, IntPtr)

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:58:40.368] Missing following objects: AirPollutionGeneratorObject, CountryMarkerObject, FedeartionMarkerObject, HomesteadMarkerObject, TownMarkerObject
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
<BuildFromModKit>d__8:MoveNext()
UnityEngine.SetupCoroutine:InvokeMoveNext(IEnumerator, IntPtr)
<ReceiveModData>d__47:MoveNext()
UnityEngine.SetupCoroutine:InvokeMoveNext(IEnumerator, IntPtr)

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:58:41.770] Disconnected with error: Server encountered an exception:

<size=60.00%>Exception: NullReferenceException
Message:Object reference not set to an instance of an object.
Source:Eco.Gameplay

System.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.get_SourceAccount()
   at Eco.Gameplay.Economy.Jobs.RecurringTransferManager.<>c__DisplayClass8_0.<TransfersForUser>b__0(RecurringTransfer x)
   at System.Linq.Enumerable.WhereEnumerableIterator`1.MoveNext()
   at Eco.Core.Controller.ControllerManager.PackageValue(IMvcNetClient boundClient, Object value, Int32 nameID)
   at Eco.Core.Controller.ControllerManager.PackageProperty(IMvcNetClient boundClient, IController controller, ISyncPropertyInfo propertyInfo)
Outer Exceptions:
Error during packaging property 'IncomeAndExpenses' of 'Eco.Gameplay.Players.User'</size>
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
NetworkManager:OnClientDisconnected(String)
System.Action`1:Invoke(T)
Eco.Shared.Networking.NetworkClient:HandleDisconnect(String)
UnityEngine.Experimental.Audio.SampleFramesHandler:Invoke(AudioSampleProvider, UInt32)
Eco.Networking.ENet.ENetUdpClient:OnDisconnected(ENetConnection, DisconnectReason)
Eco.Networking.ENet.ENetUdpPeer:HandleEvent()
Eco.Networking.ENet.ENetUdpPeer:Service(Int32)
<>c__DisplayClass63_0:<Initialize>b__0()
UnityEngine.DisplaysUpdatedDelegate:Invoke()
System.Action`1:Invoke(T)
System.Threading.ExecutionContext:RunInternal(ExecutionContext, ContextCallback, Object, Boolean)
System.Threading.ExecutionContext:Run(ExecutionContext, ContextCallback, Object)
UnityEngine.DisplaysUpdatedDelegate:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

[10:58:41.779] Missing Connecting
EcoEngine.Logging.LogManager:LogFormat(LogType, Object, String, Object[])
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogError(Object)
UI.ConnectionUI:GotoState(ConnectState)
UI.ConnectionUI:ManualUpdate()
UI.UIManager:Update()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

Unloading 7 Unused Serialized files (Serialized files now loaded: 0)

Unloading 31471 unused Assets to reduce memory usage. Loaded Objects now: 95393.
Total: 164.054700 ms (FindLiveObjects: 4.613300 ms CreateObjectMapping: 9.719800 ms MarkObjects: 129.426900 ms  DeleteObjects: 20.294300 ms)

Do you have mods installed? Does the issue happen when no mods are installed?: No vanilla version used.

More details: Server updated from 9.1.9 (running smoothly) to 9.2.1 directly. When I got the notification about 9.2 available, 9.2.1 was available.

Was able to reconnect to the server after the migration.

Directly noticed some issues:

Food at 0
Housing value at 0
Constitution marked as disabled because some error but in this case it was not something like error in part 2, second condition. It was more something like unknown error in part 2.
All laws were not working anymore and required some manual edition using admin command (/objects edit laws,ID). One was missing a condition for location when dropping garbage. Seems condition has been removed from game.
Title "Roi" has error regarding as mentioned in issue #20232 "Must set both currency and amount when setting Online and Offline Hours"

When I tried to edit the title "Roi" with the command /objects edit title,9 to take a look at this currency issue the game crashed after few seconds and I came back to home menu.

I didn't applied any change. Just typed the command, confirmed and boom crash after the popup was opened for 10-15 seconds.

Since this time the issue occurs for everybody trying to join the server.

I want to precise the server itself didn't crashed and was working "fine". Tried restart, etc but nothing fixed the problem.

File attached: log_210128080459.log log_210128084741.log log_210129084533.log migrations.log admin_commands.log

Venopsis commented 3 years ago

I just created tar.gz archive of my actual ecoserver configuration and one from backup I did before moving to 9.2.1

Let me know if you want them to investigate.

Size: ecoserver-9.1.9 - 330Mb ecoserver-9.2.1 - 305Mb

Venopsis commented 3 years ago

Hi, Applied the v9.2.2 update on server and this time it's worth:

[16:16:21.422] [6] [ Info] [Eco] Initializing IntegrationTestsPlugin...  
[16:16:21.422] [6] [ Info] [Eco] Initializing IntegrationTestsPlugin... Finished in 0.2ms

[16:16:22.362] [28] [Error] [Eco] System.AggregateException: One or more errors occurred. (Object reference not set to an instance of an object.)

System.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.Pay()
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.TryPay()
   at Eco.Gameplay.Economy.Jobs.RecurringTransferServiceExtensions.TryPayAll(IRecurringTransferService transferService)
   at Eco.Gameplay.Economy.Jobs.RecurringTransferManager.TryPayAll()
   at Eco.Gameplay.Economy.EconomyManager.Tick()
   at Eco.Core.Utils.Threading.PeriodicWorkerFactory.<>c__DisplayClass0_0.<Create>b__0(CancellationToken token)
   at Eco.Core.Utils.Threading.RepeatableActionWorker.DoRepeatableWork(CancellationToken token)
   at Eco.Core.Utils.Threading.RepeatableWorkerBase.DoWork(CancellationToken token)

[16:16:22.591] [6] [ Info] [Eco] Saving world...  
[16:16:22.920] [81] [ Info] [Eco] Skipping Windows firewall setup, platform = Unix

[16:16:22.920] [81] [ Info] [Eco] (You may need to manually open port 3000 if the EcoGameServer is inaccessible)

[16:16:30.332] [6] [ Info] [Eco] Saving world... Finished in 7,752.1ms

[16:16:30.369] [6] [ Info] [Eco] [Server Initialization]... Finished in 74,835.9ms

[16:16:30.389] [6] [ Info] [Eco] Saving...  
[16:16:32.577] [6] [ Info] [Eco] Saving... Finished in 2,178.2ms

[16:16:42.961] [21] [ Info] [Eco] No UPnP device with public ip was found

[16:16:42.976] [27] [Error] [Eco] System.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.Pay()
   at Eco.Gameplay.Economy.Jobs.RecurringTransfer.TryPay()
   at Eco.Gameplay.Economy.Jobs.RecurringTransferServiceExtensions.TryPayAll(IRecurringTransferService transferService)
   at Eco.Gameplay.Economy.Jobs.RecurringTransferManager.TryPayAll()
   at Eco.Gameplay.Economy.EconomyManager.Tick()
   at Eco.Core.Utils.Threading.PeriodicWorkerFactory.<>c__DisplayClass0_0.<Create>b__0(CancellationToken token)
   at Eco.Core.Utils.Threading.RepeatableActionWorker.DoRepeatableWork(CancellationToken token)
   at Eco.Core.Utils.Threading.RepeatableWorkerBase.DoWork(CancellationToken token)
   at Eco.Core.Utils.Threading.WorkerBase.ShutdownAsync()
   at Eco.Core.Utils.Threading.WorkerExtensions.Shutdown(IWorker worker)
   at Eco.Gameplay.Economy.EconomyPlugin.Shutdown()
   at Eco.Server.PluginManager.<>c.<ShutdownAsync>b__33_0(PluginRegistration reg)

[16:16:43.267] [27] [ Info] [Eco] Shutdown finished

The server now stop automatically after few seconds. Not even showing as online for this short running time.

Tried three times to start it but same result -> automatically proceed shutdown.

Venopsis commented 3 years ago

Any feedback?

zitrusgelb commented 3 years ago

I have a similar Issue, only that in my case it errors straight on the second migration error Venopsis got. I can also attach the log files and a backup I made before updating if you need them to investigate the error.

[14:27:36.422] [12] [ Warn] [Eco]
=================================================
Migration was performed, migrations.log was saved.
=================================================

[14:27:37.554] [5] [ Info] [Eco] [Server Initialization]... Finished in 91.870,7ms

[14:27:37.588] [12] [Error] [Eco] Failed to load server, Exception was Exception: NullReferenceException
Message:Object reference not set to an instance of an object.
Source:Eco.Gameplay

System.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransferServiceExtensions.DeregisterWages(IRecurringTransferService group)
   at Eco.Gameplay.Civics.Titles.Title.Destroyed()
   at Eco.Core.Systems.Registrar.Remove(INetObject netObj, Object obj)
   at Eco.Core.Systems.Registrar.Remove(IHasID t)
   at Eco.Gameplay.Civics.Misc.CivicsUtils.TryDestoryProposable(IProposable proposable, Player player)
   at Eco.Gameplay.Civics.Constitution.OnStateChangedInternal()
   at Eco.Gameplay.Civics.Misc.CivicsUtils.SetProposedState(IProposable proposable, ProposableState state, Boolean doScan, Boolean notify)
   at Eco.Gameplay.Civics.Misc.CivicsUtils.CheckHostState(IProposable proposable)
   at Eco.Gameplay.Civics.Misc.SimpleProposable.Valid()
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.SetupValidity(ScanScope scope, ScanSettings settings, ScanResults results)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.ScanObj(Object root, ScanSettings settings)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.Scan(ScanSettings settings)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.Scan(IEnumerable`1 objs)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.ScanAll()
   at Eco.Server.PluginManager.PostCreateAsync(StartupInfo startupInfo)
   at Eco.Server.Startup.StartAsync(StartupInfo startupInfo)

[14:27:42.625] [1] [Error] [Eco] Unhandled errorSystem.NullReferenceException: Object reference not set to an instance of an object.
   at Eco.Gameplay.Economy.Jobs.RecurringTransferServiceExtensions.DeregisterWages(IRecurringTransferService group)
   at Eco.Gameplay.Civics.Titles.Title.Destroyed()
   at Eco.Core.Systems.Registrar.Remove(INetObject netObj, Object obj)
   at Eco.Core.Systems.Registrar.Remove(IHasID t)
   at Eco.Gameplay.Civics.Misc.CivicsUtils.TryDestoryProposable(IProposable proposable, Player player)
   at Eco.Gameplay.Civics.Constitution.OnStateChangedInternal()
   at Eco.Gameplay.Civics.Misc.CivicsUtils.SetProposedState(IProposable proposable, ProposableState state, Boolean doScan, Boolean notify)
   at Eco.Gameplay.Civics.Misc.CivicsUtils.CheckHostState(IProposable proposable)
   at Eco.Gameplay.Civics.Misc.SimpleProposable.Valid()
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.SetupValidity(ScanScope scope, ScanSettings settings, ScanResults results)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.ScanObj(Object root, ScanSettings settings)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.Scan(ScanSettings settings)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.Scan(IEnumerable`1 objs)
   at Eco.Core.Utils.PropertyScanning.PropertyScanner.ScanAll()
   at Eco.Server.PluginManager.PostCreateAsync(StartupInfo startupInfo)
   at Eco.Server.Startup.StartAsync(StartupInfo startupInfo)
   at Eco.Server.ApplicationHostedService.StartAsync(CancellationToken cancellationToken)
   at Microsoft.Extensions.Hosting.Internal.Host.StartAsync(CancellationToken cancellationToken)
   at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
   at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
   at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.Run(IHost host)
   at Eco.Server.MainClass.Main(String[] args)

migration.log

Venopsis commented 3 years ago

@WeaselDog Can you please take a look at this? We are not able to continue to play even if I try different things. Someone posted an unrecoverable crash and his case (#20274) is already in progress... Mine after two days not even a comment. Also have 100+ hours on this map. Would appreciate some help :)

SlayksWood commented 3 years ago

@Venopsis Thank you for the report and sorry for the wait. Can you give link to your save files?

SlayksWood commented 3 years ago

@Venopsis I closed this one, you issue will be solved in #20274. Sorry for the wait again.

StrangeLoopGames / EcoIssues

[9.2.x] Migration from v9.1.9 to 9.2.x - Crash on join #20250