Packet processing error on quickly dropping items from inventory to the floor

Viktor Ferenczi shared this bug 4 months ago
Solved

Happened while I was very quickly dropping items from my inventory to the floor. The exception below was on server side, then the client was disconnected:


02:40:53.0687 [ERROR] Keen: System.InvalidOperationException: Nullable object must have a value.
at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)
at Sandbox.Game.MyInventory.DropItem_Implementation(MyFixedPoint amount, UInt32 itemIndex)
at VRage.Network.CallSite`7.Invoke(BitStream stream, Object obj, Boolean validate)
at VRage.Network.MyReplicationLayer.Invoke(CallSite callSite, BitStream stream, Object obj, EndpointId source, MyClientStateBase clientState, Boolean validate)
at VRage.Network.MyReplicationServer.OnEvent(MyPacketDataBitStreamBase data, CallSite site, Object obj, IMyNetObject sendAs, Nullable`1 position, EndpointId source)
at VRage.Network.MyReplicationLayer.OnEvent(MyPacketDataBitStreamBase data, NetworkId networkId, NetworkId blockedNetId, UInt32 eventId, EndpointId sender, Nullable`1 position)
at VRage.Network.MyReplicationLayer.ProcessEvent(MyPacketDataBitStreamBase data, EndpointId sender)
at VRage.Network.MyReplicationLayer.OnEvent(MyPacket packet)
at Sandbox.Engine.Multiplayer.MyTransportLayer.ProcessMessage(MyPacket p)
at Sandbox.Engine.Multiplayer.MyTransportLayer.HandleMessage(MyPacket p)
at Sandbox.Engine.Networking.MyReceiveQueue.Process(NetworkMessageDelegate handler)
System.InvalidOperationException: Nullable object must have a value.
at System.ThrowHelper.ThrowInvalidOperationException(ExceptionResource resource)
at Sandbox.Game.MyInventory.DropItem_Implementation(MyFixedPoint amount, UInt32 itemIndex)
at VRage.Network.CallSite`7.Invoke(BitStream stream, Object obj, Boolean validate)
at VRage.Network.MyReplicationLayer.Invoke(CallSite callSite, BitStream stream, Object obj, EndpointId source, MyClientStateBase clientState, Boolean validate)
at VRage.Network.MyReplicationServer.OnEvent(MyPacketDataBitStreamBase data, CallSite site, Object obj, IMyNetObject sendAs, Nullable`1 position, EndpointId source)
at VRage.Network.MyReplicationLayer.OnEvent(MyPacketDataBitStreamBase data, NetworkId networkId, NetworkId blockedNetId, UInt32 eventId, EndpointId sender, Nullable`1 position)
at VRage.Network.MyReplicationLayer.ProcessEvent(MyPacketDataBitStreamBase data, EndpointId sender)
at VRage.Network.MyReplicationLayer.OnEvent(MyPacket packet)
at Sandbox.Engine.Multiplayer.MyTransportLayer.ProcessMessage(MyPacket p)
at Sandbox.Engine.Multiplayer.MyTransportLayer.HandleMessage(MyPacket p)
at Sandbox.Engine.Networking.MyReceiveQueue.Process(NetworkMessageDelegate handler)
02:40:53.0703 [DEBUG] Keen: Packet processing error, disconnecting 76561198223054696
02:40:53.0749 [INFO] Keen: User left Viktor

Comments (6)

photo
1

The client did not have any relevant log messages:


...

2021-01-16 02:40:19.839 - Thread: 1 -> GUI Stats: Update 0.194914611111111, Draw 0.324415611111111

2021-01-16 02:40:29.560 - Thread: 1 -> GC Memory: 2273.485 / 2273.485 MB

2021-01-16 02:40:41.012 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.LoadContent

2021-01-16 02:40:46.301 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.UnloadContent - START

2021-01-16 02:40:46.301 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.UnloadContent - END

2021-01-16 02:40:50.919 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.LoadContent

2021-01-16 02:40:52.288 - Thread: 1 -> GUI Stats: Update 0.211697111111111, Draw 0.312797833333333

2021-01-16 02:40:52.668 - Thread: 1 -> STATISTICS LEGEND,time,ReceivedPerSecond,SentPerSecond,PeakReceivedPerSecond,PeakSentPerSecond,OverallReceived,OverallSent,CPULoadSmooth,ThreadLoadSmooth,GetOnlinePlayerCount,Ping,GCMemoryUsed,ProcessMemory,PCUBuilt,PCU,GridsCount,RenderCPULoadSmooth,RenderGPULoadSmooth,HardwareCPULoad,HardwareAvailableMemory,FrameTime,LowSimQuality,FrameTimeLimit,FrameTimeCPU,FrameTimeGPU,CPULoadLimit,TrackedMemory,GCMemoryAllocated,PersistedEncounters,EncounterEntities

2021-01-16 02:40:52.668 - Thread: 1 -> STATISTICS,1320.3666667,0.08817101,0.007520676,2.424301,0.06268692,114.9059,10.26528,20.69112,57.06266,4,50,2338.524,9663.605,168602,2000000,267,22.98402,96.60268,0.09971423,41809,16.67434,0,16.66667,3.832433,16.10786,100,5831607806,2338.524,0,0

2021-01-16 02:40:52.668 - Thread: 1 -> MEMORY LEGEND,Srv,Uav,Read,Debug,Index,Audio,SrvUav,Vertex,Buffers,Physics,Planets,Systems,Textures,Indirect,Constant,RwTextures,Dx11Render,MeshBuffers,FileTextures,DepthStencil,TileTextures,Voxels-Native,CustomTextures,HeightmapFaces,Mesh GPU Buffers,BitStreamBuffers,GeneratedTextures,FileArrayTextures,NativeDictionaries,CubemapDataBuffers,HeightDetailTexture,MyDeviceWriteBuffers,ShadowCascadesStatsBuffers,AI_PathFinding,EpicOnlineServices

2021-01-16 02:40:52.668 - Thread: 1 -> MEMORY VALUES,1,1,0,1,58,905,59,268,459,165,73,5561,3107,0,0,425,3567,0,2067,126,0,40,63,48,38,22,17,407,785,24,1,30,0,0,0

2021-01-16 02:40:57.671 - Thread: 1 -> RequestRespawn

2021-01-16 02:40:57.890 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.UnloadContent - START

2021-01-16 02:40:57.890 - Thread: 1 -> MyGuiScreenTerminal MyGuiScreenBase.UnloadContent - END

2021-01-16 02:40:59.571 - Thread: 1 -> GC Memory: 2337.193 / 2337.193 MB


<reconnected to the online game>


2021-01-16 02:41:02.933 - Thread: 1 -> MyGuiScreenMainMenu MyGuiScreenBase.LoadContent

...

photo
1

Server and client time zone was the same and clocks synchronized properly. Verified by manually comparing the times, difference was less than 1 second. So log correlation was good.

photo
1

Hello, Viktor,


Thank you for your report. Could you please attach here the whole log and the save of your server? Do you use any mods on your server? Do you have reliable reproduction steps of your issue (e.g. how many items did you throw away, etc.). We will appreciate any additional information.


Kind Regards

Keen Software House: QA Department

photo
1

I will attempt to do a quick reproduction with no mods (I used five) and on a non-Torch server (because I used a Torch based one).

It crashed on my 3 times so far when I just tried to drop the 3 default tools from my inventory in quick succession.

photo
1

Hello, thank you!


Kind Regards

Keen Software House: QA Department

photo
photo
1

Hello, Viktor!


Any updates with your testing on an un-modded and non torch server? Thank you.


Kind Regards

Keen Software House: QA Department

photo
1

I could not reproduce this so far. It was most likely a problem with some mod.

I will leave more information here if I see this happening again.

Until then please feel free to close this ticket with "cannot reproduce".

Viktor

photo
1

Hello, Viktor!


Thank you for your reply. I'm closing this ticket.


Kind Regards

Keen Software House: QA Department

photo