search

RandyKnapp / ValheimMods

179 stars 137 forks source link

[BUG] - zRPC config sync issue #223

Closed sbtoonz closed 3 years ago

sbtoonz commented 3 years ago 
[Info   : Unity Log] 05/19/2021 18:49:41: Exception in ZRpc::HandlePackage: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
  at System.IO.MemoryStream.InternalReadInt32 () [0x00034] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at (wrapper remoting-invoke-with-check) System.IO.MemoryStream.InternalReadInt32()
  at System.IO.BinaryReader.ReadInt32 () [0x00015] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at ZPackage.ReadInt () [0x00000] in <fda64833b4b74020987bc5f624178286>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadKnown (System.Int64 sender, ZPackage pkg, System.Collections.Generic.Dictionary`2[TKey,TValue] outDict) [0x0000e] in <8cd03007244c43338cfee18228867dea>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadServerKnown (System.Collections.Generic.Dictionary`2[TKey,TValue] dict, ZPackage pkg) [0x0001b] in <8cd03007244c43338cfee18228867dea>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.RPC_ServerKnown (System.Int64 sender, ZPackage pkg) [0x00001] in <8cd03007244c43338cfee18228867dea>:0
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at RoutedMethod`1[T].Invoke (System.Int64 rpc, ZPackage pkg) [0x0001d] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper dynamic-method) ZRoutedRpc.DMD<ZRoutedRpc::HandleRoutedRPC>(ZRoutedRpc,ZRoutedRpc/RoutedRPCData)
  at ZRoutedRpc.RPC_RoutedRPC (ZRpc rpc, ZPackage pkg) [0x00023] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at ZRpc+RpcMethod`1[T].Invoke (ZRpc rpc, ZPackage pkg) [0x0001d] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper dynamic-method) ZRpc.DMD<ZRpc::HandlePackage>(ZRpc,ZPackage)
  at ZRpc.Update (System.Single dt) [0x0003e] in <fda64833b4b74020987bc5f624178286>:0
jsza commented 3 years ago

Hi, thanks for the report. I've so far been unable to reproduce this. Could you post a list of mods you're running?

sbtoonz commented 3 years ago

https://valheim.thunderstore.io/package/VMP/VMPack/

Let me garner client and server side logs

this is easily triggered on creature kill when loot drops are in the area

Let me also get my loottables and legendary jsons where you can see them

sbtoonz commented 3 years ago

narrowed it down to another mod version mismatch between client and server causing a zRPC failure within the interaction on that mod somehow causing a collapse of zRPC for all other mods reliant on it to communicate

sbtoonz commented 3 years ago

I am back

this happens now again specifically when using dedicated server

I get RPC NRE in local gameplay as well

with JUST epic loot installed

Log From player side dedicated with all mods installed LogOutput.log

https://valheim.thunderstore.io/package/VMP/VMPack/

Modpack being used

sbtoonz commented 3 years ago

seems to happen no matter the char I use as well

sbtoonz commented 3 years ago 
[Info   : Unity Log] 06/10/2021 13:11:54: Done fading color

[Error  : Unity Log] EndOfStreamException: Unable to read beyond the end of the stream.
Stack trace:
System.IO.BinaryReader.ReadString () (at <eae584ce26bc40229c1b1aa476bfa589>:0)
ZPackage.ReadString () (at <3d649eb5da984bc8a4d5b86d03245dc4>:0)
EpicLoot.Adventure.BountyTargetInfo.FromPackage (ZPackage pkg) (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.BountyInfo.FromPackage (ZPackage pkg) (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.BountyTarget.Reinitialize () (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.BountyTarget.Awake () (at <ea31350714a140bea214f1f60c7a8293>:0)
UnityEngine.GameObject:AddComponent()
EpicLoot.Adventure.Character_Start_Patch:Postfix(Character)
Character:DMD<Character::Start>(Character)
Humanoid:Start()

[Error  : Unity Log] EndOfStreamException: Unable to read beyond the end of the stream.
Stack trace:
System.IO.BinaryReader.ReadString () (at <eae584ce26bc40229c1b1aa476bfa589>:0)
ZPackage.ReadString () (at <3d649eb5da984bc8a4d5b86d03245dc4>:0)
EpicLoot.Adventure.BountyTargetInfo.FromPackage (ZPackage pkg) (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.BountyInfo.FromPackage (ZPackage pkg) (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.BountyTarget.Reinitialize () (at <ea31350714a140bea214f1f60c7a8293>:0)
EpicLoot.Adventure.Character_Start_Patch.Postfix (Character __instance) (at <ea31350714a140bea214f1f60c7a8293>:0)
(wrapper dynamic-method) Character.DMD<Character::Start>(Character)
Humanoid.Start () (at <3d649eb5da984bc8a4d5b86d03245dc4>:0)

Single player login issue that is intermittent and also surrounding ZPackage.ReadString

sbtoonz commented 3 years ago

getting the error in single player with only EL installed (and extended data framework ofc)

danbartl commented 3 years ago

Hi I got a similar error, no clue what causes it:

[Info   : Unity Log] 06/13/2021 22:05:19: Exception in ZRpc::HandlePackage: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
  at System.IO.__Error.EndOfFile () [0x0000a] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.IO.MemoryStream.InternalReadInt32 () [0x00034] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at (wrapper remoting-invoke-with-check) System.IO.MemoryStream.InternalReadInt32()
  at System.IO.BinaryReader.ReadInt32 () [0x00015] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at ZPackage.ReadInt () [0x00000] in <3d649eb5da984bc8a4d5b86d03245dc4>:0 
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadKnown (System.Int64 sender, ZPackage pkg, System.Collections.Generic.Dictionary`2[TKey,TValue] outDict) [0x0000e] in <ea31350714a140bea214f1f60c7a8293>:0 
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadServerKnown (System.Collections.Generic.Dictionary`2[TKey,TValue] dict, ZPackage pkg) [0x0001b] in <ea31350714a140bea214f1f60c7a8293>:0 
  at EpicLoot.PlayerKnown.PlayerKnownManager.RPC_ServerKnown (System.Int64 sender, ZPackage pkg) [0x00001] in <ea31350714a140bea214f1f60c7a8293>:0 
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0 
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at RoutedMethod`1[T].Invoke (System.Int64 rpc, ZPackage pkg) [0x0001d] in <3d649eb5da984bc8a4d5b86d03245dc4>:0 
  at ZRoutedRpc.HandleRoutedRPC (ZRoutedRpc+RoutedRPCData data) [0x00022] in <3d649eb5da984bc8a4d5b86d03245dc4>:0 
  at ZRoutedRpc.RPC_RoutedRPC (ZRpc rpc, ZPackage pkg) [0x00023] in <3d649eb5da984bc8a4d5b86d03245dc4>:0 
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0 
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0 
  at ZRpc+RpcMethod`1[T].Invoke (ZRpc rpc, ZPackage pkg) [0x0001d] in <3d649eb5da984bc8a4d5b86d03245dc4>:0 
  at (wrapper dynamic-method) ZRpc.DMD<ZRpc::HandlePackage>(ZRpc,ZPackage)
  at ZRpc.Update (System.Single dt) [0x0003e] in <3d649eb5da984bc8a4d5b86d03245dc4>:0

after the error, my game has frequent desync errors (invisible mobs etc.)

Here is the output log: LogOutput (2).log

sbtoonz commented 3 years ago

The desync I can also attribute to this ZRPC failure

I also watch lots of other mods that sync data fail in the bepinex console shortly after this when attempting to sync data

as if the pipeline is consumed and jammed stuck

danbartl commented 3 years ago

Just to narrow it down, did you edit any of the JSONs? I did, without error though. Going to try with vanilla Jsons next

sbtoonz commented 3 years ago

loottables.json is quite heavily edited

yet I yield this error with normal loottables as well

sbtoonz commented 3 years ago

Same experience running the loot table from thunder store or my own

sbtoonz commented 3 years ago

https://github.com/RandyKnapp/ValheimMods/blob/main/EpicLoot/PlayerKnown/PlayerKnownManager.cs#L155

Seems to be the culprit operation

Looks like when a player has an overabundant list of recipes/items the string fails to read out as the written value is too long

idk if chunking this operation is logical but I will attempt to code something like that and PR it

sbtoonz commented 3 years ago

https://github.com/RandyKnapp/ValheimMods/pull/275

For initial issue

virtualbjorn commented 3 years ago

LogOutput.log

Still able to get the issue, here's my LogOut file

virtualbjorn commented 3 years ago 
[Info   : Unity Log] 05/19/2021 18:49:41: Exception in ZRpc::HandlePackage: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
  at System.IO.MemoryStream.InternalReadInt32 () [0x00034] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at (wrapper remoting-invoke-with-check) System.IO.MemoryStream.InternalReadInt32()
  at System.IO.BinaryReader.ReadInt32 () [0x00015] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at ZPackage.ReadInt () [0x00000] in <fda64833b4b74020987bc5f624178286>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadKnown (System.Int64 sender, ZPackage pkg, System.Collections.Generic.Dictionary`2[TKey,TValue] outDict) [0x0000e] in <8cd03007244c43338cfee18228867dea>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.LoadServerKnown (System.Collections.Generic.Dictionary`2[TKey,TValue] dict, ZPackage pkg) [0x0001b] in <8cd03007244c43338cfee18228867dea>:0
  at EpicLoot.PlayerKnown.PlayerKnownManager.RPC_ServerKnown (System.Int64 sender, ZPackage pkg) [0x00001] in <8cd03007244c43338cfee18228867dea>:0
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at RoutedMethod`1[T].Invoke (System.Int64 rpc, ZPackage pkg) [0x0001d] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper dynamic-method) ZRoutedRpc.DMD<ZRoutedRpc::HandleRoutedRPC>(ZRoutedRpc,ZRoutedRpc/RoutedRPCData)
  at ZRoutedRpc.RPC_RoutedRPC (ZRpc rpc, ZPackage pkg) [0x00023] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper managed-to-native) System.Reflection.MonoMethod.InternalInvoke(System.Reflection.MonoMethod,object,object[],System.Exception&)
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00032] in <eae584ce26bc40229c1b1aa476bfa589>:0
   --- End of inner exception stack trace ---
  at System.Reflection.MonoMethod.Invoke (System.Object obj, System.Reflection.BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00048] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Reflection.MethodBase.Invoke (System.Object obj, System.Object[] parameters) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvokeImpl (System.Object[] args) [0x000e7] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.MulticastDelegate.DynamicInvokeImpl (System.Object[] args) [0x00008] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at System.Delegate.DynamicInvoke (System.Object[] args) [0x00000] in <eae584ce26bc40229c1b1aa476bfa589>:0
  at ZRpc+RpcMethod`1[T].Invoke (ZRpc rpc, ZPackage pkg) [0x0001d] in <fda64833b4b74020987bc5f624178286>:0
  at (wrapper dynamic-method) ZRpc.DMD<ZRpc::HandlePackage>(ZRpc,ZPackage)
  at ZRpc.Update (System.Single dt) [0x0003e] in <fda64833b4b74020987bc5f624178286>:0

Still able to get this error on v0.8.2