tModLoader / tModLoader

A mod to make and play Terraria mods. Supports Terraria 1.4 (and earlier) installations
https://www.tmodloader.net/
MIT License
4.19k stars 1.88k forks source link

Intermittent issues connecting specific characters to servers #2818

Closed entropiccode closed 2 years ago

entropiccode commented 2 years ago

Version

Latest 1.4-stable

OS

Windows

Platform

Steam

This bug affects

Gameplay as a Player

Description

When logging into a dedicated server with specific characters, the connection will hang on 'Receiving tile data' for a majority of attempts. A WARN log event or two will appear in the client log on the first attempt during a session, but not after that.

Log File

client.log server.log

Steps to reproduce

  1. Click 'Multiplayer'
  2. Click 'Join via IP'
  3. Choose which character to use.
  4. Enter the IP or hostname of a remote dedicated server, or choose the connection from the saved list if connected previously. 4a. Enter the port number for the server if connecting for the first time. 4b. Enter the server password if required.

Expected Behavior

Character connects to the server and loads into the world without issue.

Actual Behavior

The connection will hang on 'Receiving tile data'.

Reproduction frequency

Gauging frequency of this issue is difficult as sometimes server login will work on repeat attempts, while other times it will fail from computer start up. If the character in question sees world loading issues/corruption during time spent in the world, however, their next login attempt will always hang on 'Receiving tile data'.

Additional Information

This WARN log event is reliably seen in client.log the first time an affected character attempts to connect to the server in a session:

[08:56:46.315] [Main Thread/WARN] [tML]: Silently Caught Exception: 
System.IndexOutOfRangeException: Index was outside the bounds of the array.
   at Terraria.NetMessage.DecompressTileBlock_Inner(BinaryReader reader, Int32 xStart, Int32 yStart, Int32 width, Int32 height) in tModLoader\Terraria\NetMessage.cs:line 2001
   at Terraria.NetMessage.DecompressTileBlock(Byte[] buffer, Int32 bufferStart, Int32 bufferLength) in tModLoader\Terraria\NetMessage.cs:line 1995
   at DMD<Terraria.MessageBuffer::GetData>(MessageBuffer this, Int32 start, Int32 length, Int32& messageType)
   at Terraria.NetMessage.CheckBytes(Int32 bufferIndex) in tModLoader\Terraria\NetMessage.cs:line 2235
   at Terraria.Main.DoUpdate(GameTime& gameTime) in tModLoader\Terraria\Main.cs:line 12797
   at DMD<Terraria.Main::Update>(Main this, GameTime gameTime)
   at ImproveGame.Common.Systems.NetPasswordSystem.CheckConnected(orig_Update orig, Main self, GameTime gameTime) in ImproveGame\Common\Systems\NetPasswordSystem.cs:line 18
   at Microsoft.Xna.Framework.Game.Tick() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 546
   at Microsoft.Xna.Framework.Game.RunLoop() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 878
   at Microsoft.Xna.Framework.Game.Run() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 419
   at Terraria.Program.LaunchGame_(Boolean isServer) in tModLoader\Terraria\Program.cs:line 235
   at Terraria.Program.LaunchGame(String[] args, Boolean monoArgs) in tModLoader\Terraria\Program.cs:line 196
   at MonoLaunch.<>c__DisplayClass1_0.<Main>b__0() in tModLoader\Terraria\MonoLaunch.cs:line 52
   at System.Threading.Thread.StartCallback()

This WARN log event is occassionally seen in client.log the first time an affected character attempts to connect to the server in a session, but not always.

[08:56:46.335] [Main Thread/WARN] [tML]: Silently Caught Exception: 
System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
   at System.IO.BinaryReader.ReadString()
   at DMD<Terraria.MessageBuffer::GetData>(MessageBuffer this, Int32 start, Int32 length, Int32& messageType)
   at Terraria.NetMessage.CheckBytes(Int32 bufferIndex) in tModLoader\Terraria\NetMessage.cs:line 2235
   at Terraria.Main.DoUpdate(GameTime& gameTime) in tModLoader\Terraria\Main.cs:line 12797
   at DMD<Terraria.Main::Update>(Main this, GameTime gameTime)
   at ImproveGame.Common.Systems.NetPasswordSystem.CheckConnected(orig_Update orig, Main self, GameTime gameTime) in ImproveGame\Common\Systems\NetPasswordSystem.cs:line 18
   at Microsoft.Xna.Framework.Game.Tick() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 546
   at Microsoft.Xna.Framework.Game.RunLoop() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 878
   at Microsoft.Xna.Framework.Game.Run() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 419
   at Terraria.Program.LaunchGame_(Boolean isServer) in tModLoader\Terraria\Program.cs:line 235
   at Terraria.Program.LaunchGame(String[] args, Boolean monoArgs) in tModLoader\Terraria\Program.cs:line 196
   at MonoLaunch.<>c__DisplayClass1_0.<Main>b__0() in tModLoader\Terraria\MonoLaunch.cs:line 52
   at System.Threading.Thread.StartCallback()

Characters/World in question are Journey Mode.

The only characters in question that I can reliably reproduce this issue on are characters that were/are stored in the Steam Cloud. The issue persists after removing the character from the Steam Cloud. I went into the character's save data and removed all .MAP and .TMAP files to confirm that it wasn't persistent mini-map data causing the problem, however there was no change in behavior.

The remote server I tested with is hosted by aleforge.net. They utilize linux as their server OS and do not seem to have a steam installation associated with the server instance, indicated by error messages in the server log. I was unable to reproduce this issue on the same world on a local dedicated server running on my Windows PC.

The PC that characters were originally created on seems to have no bearing on this issue. I created a new character on one PC, then added that character to Steam Cloud. I was then able to log into the server with this character from a second PC and play without issue. Going back to the first PC, this character encountered the described issue. This may suggest an issue with syncing with Steam Cloud, however I have other characters who are also on the Steam Cloud that can access the server without issues.

Here is an example of the world loading issues that the affected characters will see: Capture 2022-08-09 19_14_17

The terrain that is missing in this screenshot exists for other characters not affected by this issue, as demonstrated here: Capture 2022-08-09 19_16_15

The world that has been tested on was generated locally, then uploaded to the aleforge servers as per their own instructions, due to the known issue with tmodloader and setting difficulty on auto-generated worlds.

entropiccode commented 2 years ago

Additionally, if I quickly cancel out of the 'Receiving tile data' screen and attempt to join the server again, I will receive a '[character name] is already on this server.' message.

Rebooting the remote dedicated server does not seem to impact my ability to log into the server with affected characters.

Mod items or mod interactions do not seem to be affecting this, as characters that are in Calamity end-game with appropriate gear and item progression/research are able to access the server without issue, but the characters that are affected have not yet killed a boss.

Does not seem to be a network issue as some characters can connect to the server reliably.

Both affected characters did have a spawn point set via bed in the world itself, however breaking the bed doesn't resolve the connection issues.

Symulation12 commented 2 years ago

I have been having the same issue. Connecting from a 1.4-stable client on Windows 10 to a dedicated server running the same version on Ubuntu Server 22.04.01 LTS.

The client.log on my local machine gives the same kind of warning:

System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
   at System.IO.BinaryReader.ReadString()
   at DMD<Terraria.MessageBuffer::GetData>(MessageBuffer this, Int32 start, Int32 length, Int32& messageType)
   at Terraria.NetMessage.CheckBytes(Int32 bufferIndex) in tModLoader\Terraria\NetMessage.cs:line 2235
   at Terraria.Main.DoUpdate(GameTime& gameTime) in tModLoader\Terraria\Main.cs:line 12797
   at DMD<Terraria.Main::Update>(Main this, GameTime gameTime)
   at ImproveGame.Common.Systems.NetPasswordSystem.CheckConnected(orig_Update orig, Main self, GameTime gameTime) in ImproveGame\Common\Systems\NetPasswordSystem.cs:line 18
   at Microsoft.Xna.Framework.Game.Tick() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 546
   at Microsoft.Xna.Framework.Game.RunLoop() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 878
   at Microsoft.Xna.Framework.Game.Run() in D:\a\tModLoader\tModLoader\FNA\src\Game.cs:line 419
   at Terraria.Program.LaunchGame_(Boolean isServer) in tModLoader\Terraria\Program.cs:line 235
   at Terraria.Program.LaunchGame(String[] args, Boolean monoArgs) in tModLoader\Terraria\Program.cs:line 196
   at MonoLaunch.<>c__DisplayClass1_0.<Main>b__0() in tModLoader\Terraria\MonoLaunch.cs:line 52
   at System.Threading.Thread.StartCallback()

The server.log on the dedicated server will also consistently throw this warning:

[09:24:56.097] [Main Thread/WARN] [tML]: Silently Caught Exception: 
System.BadImageFormatException: Read out of bounds.
   at System.Reflection.Throw.OutOfBounds()
   at System.Diagnostics.StackTraceSymbols.GetSourceLineInfo(Assembly assembly, String assemblyPath, IntPtr loadedPeAddress, Int32 loadedPeSize, Boolean isFileLayout, IntPtr inMemoryPdbAddress, Int32 inMemoryPdbSize, Int32 methodToken, Int32 ilOffset, String& sourceFile, Int32& sourceLine, Int32& sourceColumn)
   at System.Diagnostics.StackFrameHelper.InitializeSourceInfo(Int32 iSkip, Boolean fNeedFileInfo, Exception exception)
   at System.Diagnostics.StackTrace.CaptureStackTrace(Int32 skipFrames, Boolean fNeedFileInfo, Exception e)
   at System.Diagnostics.StackTrace..ctor(Boolean fNeedFileInfo)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.CreateException(SocketError error, Boolean forAsyncThrow)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.SendAsync(Socket socket, CancellationToken cancellationToken)
   at System.Net.Sockets.NetworkStream.BeginWrite(Byte[] buffer, Int32 offset, Int32 count, AsyncCallback callback, Object state)
   at DMD<Terraria.Net.Sockets.TcpSocket::Terraria.Net.Sockets.ISocket.AsyncSend>(TcpSocket this, Byte[] data, Int32 offset, Int32 size, SocketSendCallback callback, Object state)
   at Terraria.Net.NetManager.SendData(ISocket socket, NetPacket packet)
   at Terraria.GameContent.NetModules.NetLiquidModule.PrepareAndSendToEachPlayerSeparately()
   at Terraria.Liquid.UpdateLiquid()
   at Terraria.WorldGen.UpdateWorld_Inner()
   at DMD<Terraria.WorldGen::UpdateWorld>()
   at DMD<Terraria.Main::DoUpdateInWorld>(Main this, Stopwatch sw)
   at Terraria.Main.DoUpdate(GameTime& gameTime)
   at Terraria.Main.Update(GameTime gameTime)
   at DMD<Terraria.Main::DedServ_PostModLoad>(Main this, Boolean& reloadMods)
   at Terraria.Main.DedServ()
   at Terraria.Program.LaunchGame_(Boolean isServer)
   at Terraria.Program.LaunchGame(String[] args, Boolean monoArgs)
   at MonoLaunch.<>c__DisplayClass1_0.<Main>b__0()
   at MonoLaunch.Main(String[] args)

There are two characters are consistently unable to connect and get the hang on Receiving Tile Data: Complete! It is only two characters though, any other character I try to connect works fine, so far I've tested 2 other characters. The two afflicted characters also seem to have no issue connecting to a local world, and in testing with a different world on the dedicated server they can connect as well. It appears to be a specific combination of the world and the characters

I've tried various combinations of enabled mods and found that the issue doesn't go away if I disable all the mods on the server and there doesn't seem to be any pattern to which enabled mods cause the error.

I did notice, however, that the characters that were unable to connect had significantly larger save file sizes than the ones that could connect. The character that is unable to connect has a .tplr file size of 773kb, and the ones that can connect have a save file size of around 11kb.

The server log comes from my dedicated server, and the client log is from my local machine. server.log client.log The affected player I have access to and the world in question player.zip world.zip

The mods the world were originally created with are: The Stars Above, Subworld Library, Calamity + Music + Vanities, Terrarchitect, Recipe Browser, Boss Checklist, Magic Storage, Ore Excavator, and Cellphone is Wormhole

The error still occurs without these enabled, but it may be relevant for data they left on the server.

It's certainly very possible this is a mod related issue, but in my own testing I haven't been able to isolate a mod that is causing the issue as the problem occurs even when all mods are disabled.

entropiccode commented 2 years ago

I did notice, however, that the characters that were unable to connect had significantly larger save file sizes than the ones that could connect. The character that is unable to connect has a .tplr file size of 773kb, and the ones that can connect have a save file size of around 11kb.

Adding my data here, the character that I could consistently trigger this issue with has a .plr size of 13kb and a .tplr size of 9kb, whereas a character I could consistently connect with had a .plr size of 74kb and a .tplr size of 2,043kb. This lines up with their overall progression, as the first character was still pre-boss, the second character had fully cleared Calamity progression.

Metallumere commented 2 years ago

I too am having this issue, with an identical console.log exception.

System.IndexOutOfRangeException: Index was outside the bounds of the array. at Terraria.NetMessage.DecompressTileBlock_Inner blah blah blah

I'm guessing this has something to do with changes made 13 days ago in this commit.

In particular, it seems like the exception is complaining about these lines.

Here's my client.log too.

Chicken-Bones commented 2 years ago

To everyone experiencing this issue (the more frequent and repeatable the better). Please come to Discord and message me (or @Chicken-Bones) and I'll find some time to send you test builds and get to the bottom of this