Author Topic: TNet/RFC Debugging  (Read 26163 times)

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #15 on: June 26, 2014, 11:56:15 AM »
The server won't tell the clients to disconnect, but it may disconnect them if they sent bad data.

Off the top of my head, nothing would kick someone off and not let them reconnect. TNet doesn't have a blacklist. I can only suggest running the server in debug (from visual studio) and logging the packets that arrive.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #16 on: July 09, 2014, 09:14:50 PM »
Just experienced a mass disconnect of all players in a channel. I managed to snag a log from one of them and figured out where Close() is called on the client by putting Logs everywhere. Logs printed in this order:

  1. ProcessBuffer called close(true)
  2.  
  3. OnReceive called Close(true) 3
  4.  
  5. Close called w/ notify: True
  6.  
  7. Received Packet.Disconnect from Server.
  8.  



Here are where those were printed.

In TNTcpProtocol.cs ~line 588 UnityEngine.Debug.Log ("OnReceive called Close(true) 3");
In TNTcpProtocol.cs ~line 617 "UnityEngine.Debug.Log ("ProcessBuffer called close(true)")


  1.        
  2. void OnReceive (IAsyncResult result)
  3.         {
  4.                 if (stage == Stage.NotConnected) return;
  5.                 int bytes = 0;
  6.  
  7.                 try
  8.                 {
  9.                         bytes = mSocket.EndReceive(result);
  10.                 }
  11.                 catch (System.Exception ex)
  12.                 {
  13.                         Error(ex.Message);
  14.                         Disconnect();
  15.                         return;
  16.                 }
  17.                 lastReceivedTime = DateTime.Now.Ticks / 10000;
  18.  
  19.                 if (bytes == 0)
  20.                 {
  21.                         UnityEngine.Debug.Log ("OnReceive called Close(true) 1");
  22.                         Close(true);
  23.                 }
  24.                 else if (ProcessBuffer(bytes))
  25.                 {
  26.                         if (stage == Stage.NotConnected) return;
  27.  
  28.                         try
  29.                         {
  30.                                 // Queue up the next read operation
  31.                                 mSocket.BeginReceive(mTemp, 0, mTemp.Length, SocketFlags.None, OnReceive, null);
  32.                         }
  33.                         catch (System.Exception ex)
  34.                         {
  35.                                 Error(ex.Message);
  36.                                 UnityEngine.Debug.Log ("OnReceive called Close(false) 2");
  37.                                 Close(false);
  38.                         }
  39.                 }
  40.                 else
  41.                 {
  42.                         UnityEngine.Debug.Log ("OnReceive called Close(true) 3");
  43.                         Close(true);
  44.                 }
  45.         }
  46.  
  47.         /// <summary>
  48.         /// See if the received packet can be processed and split it up into different ones.
  49.         /// </summary>
  50.  
  51.         bool ProcessBuffer (int bytes)
  52.         {
  53.                 if (mReceiveBuffer == null)
  54.                 {
  55.                         // Create a new packet buffer
  56.                         mReceiveBuffer = Buffer.Create();
  57.                         mReceiveBuffer.BeginWriting(false).Write(mTemp, 0, bytes);
  58.                 }
  59.                 else
  60.                 {
  61.                         // Append this data to the end of the last used buffer
  62.                         mReceiveBuffer.BeginWriting(true).Write(mTemp, 0, bytes);
  63.                 }
  64.  
  65.                 for (int available = mReceiveBuffer.size - mOffset; available >= 4; )
  66.                 {
  67.                         // Figure out the expected size of the packet
  68.                         if (mExpected == 0)
  69.                         {
  70.                                 mExpected = mReceiveBuffer.PeekInt(mOffset);
  71.  
  72.                                 if (mExpected < 0 || mExpected > 16777216)
  73.                                 {
  74.                                         Close(true);
  75.                                         UnityEngine.Debug.Log ("ProcessBuffer called close(true)");
  76.                                         return false;
  77.                                 }
  78.                         }
  79.  


In TNGameClient.cs ProcessPacket() case Packet.Disconnect  is hit.

Any idea what's going on?

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #17 on: July 10, 2014, 07:44:13 PM »
If "else Close(true);" is hit, then ProcessBuffer returned 'false', meaning the packet was not able to be processed. Looking at the function, that only happens in one place:
  1.                         // Figure out the expected size of the packet
  2.                         if (mExpected == 0)
  3.                         {
  4.                                 mExpected = mReceiveBuffer.PeekInt(mOffset);
  5.  
  6.                                 if (mExpected < 0 || mExpected > 16777216)
  7.                                 {
  8.                                         Close(true);
  9.                                         return false;
  10.                                 }
  11.                         }
So TNet checks the incoming buffer, and the expected number of bytes for the packet is invalid, indicating a malformed packet. Question is, how did it get to that? And why would everyone be disconnected? If anything, a single player's bad buffer should only disconect that player, not everyone.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #18 on: July 16, 2014, 10:37:17 PM »
Ran into the same issue again tonight. We had 15 people all singing "Happy Birthday" and sending UDP voice every which way . Had a couple cases where the expected number of bytes is invalid, where we hit

  1. if (mExpected < 0 || mExpected > 16777216)
  2.  

and also ran into one where bytes == 0.

  1.         void OnReceive (IAsyncResult result)
  2.         {
  3.                 if (stage == Stage.NotConnected) return;
  4.                 int bytes = 0;
  5.  
  6.                 try
  7.                 {
  8.                         bytes = mSocket.EndReceive(result);
  9.                 }
  10.                 catch (System.Exception ex)
  11.                 {
  12.                         Error(ex.Message);
  13.                         Disconnect();
  14.                         return;
  15.                 }
  16.                 lastReceivedTime = DateTime.Now.Ticks / 10000;
  17.  
  18.                 if (bytes == 0)
  19.                 {
  20.                         UnityEngine.Debug.Log ("OnReceive called Close(true) 1");
  21.                         Close(true);
  22.                 }

It seems a malformed packet is being sent to all players, causing them to disconnect. Why do we call Close() in these cases of bad packets instead of just throwing the bad packet out?

Some other info, when everybody gets disconnected, the other player's do not leave the channel, I don't think. From my point of view in the game, everybody's avatar is frozen in the state they were in when everybody was disconnected (when the malformed packet is sent). When I exit the channel and rejoin the same channel (or even close the application and rejoin), everybody is still frozen in their last state. It's as if the player's were booted but never removed from the channel.

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #19 on: July 17, 2014, 03:15:23 AM »
Because we don't know where the packet ends. Remember, TCP is a stream protocol. it has no end. This is why I record the packet size at the beginning (the "mExpected" value). If it's invalid, then there is no way to determine where the next packet begins and it's safer to just disconnect the player.

That said, why would everyone get disconnected in this case? Only the player who sent the malformed packet should get booted.

P.S. You mention sending UDP voice... UDP packets can arrive in a different order than they are sent, and according to the specs, UDP packets will either arrive fully, or not at all, so I question how they can get malformed. Have you tried using only TCP and seeing if that resolves the issue? If so maybe we need to have a closer look at what happens with UDP traffic.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #20 on: July 17, 2014, 08:19:54 AM »
I totally didn't realize I was in the TNTcpProtocol file...so not being able to throw out the packet makes sense.

Quote
That said, why would everyone get disconnected in this case? Only the player who sent the malformed packet should get booted.

1. If Player A sends out a malformed TCP packet to everybody, wouldn't everybody have to close the connection? I don't understand why the sender would be booted from the way the code is written. The Close() calls are in OnReceive and OnProcessBuffer(). Is there a way on the client to debug and see who the sender is and possibly what RFC it was trying to send?

2. Also, can you explain why we Close if if (bytes == 0) in OnReceive()?

3. More possible symptoms, that I thought were unrelated but you never know...

  1. Failed to call RFC VRC_EventDispatcherRFC._TriggerAudioSource: failed to convert parameters
  2.   Expected args: System.Int32, System.String
  3.   Received args: System.Byte[], System.Int32
  4.  

I understand that it says the passed params and expected params aren't matching up, but it doesn't happen all the time. I've checked and double checked to make sure our function params and RFC caller params are in sync.

4. Quick shower thought, could something be happening to TCP packets when a ton of UDP is being sent at the same time? At the time of the crash, we a number of TCP packets being sent on repeat (maybe not a good idea?) as well as all the voice UDP. I've know I've heard about issues using both TCP and UDP at the same time...
« Last Edit: July 17, 2014, 05:38:11 PM by gg67 »

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #21 on: July 18, 2014, 07:49:56 AM »
1. Player packets go through the server, and it's the server that boots players who send malformed data. The server won't forward a malformed packet. You can see who the sender is by putting a log entry where the "mExpected" check fails -- line 599 of TNTcpProtocol.cs. Receiving happens on separate threads, then packets get added to the incoming buffer, and the Game Server processes them on line 334 of TNGameServer.cs.

2. Bytes 0 means a closed connection. It's what gets sent when you gracefully close the socket.

4. I know of no reason why TCP would be getting affected by UDP traffic. Heavy UDP usage may cause delays in TCP traffic I believe, but that's about it. Also not sure what you mean by "being sent on repeat"? In any case as I mentioned you can try disabling UDP (just run the server without the -udp option) and see if the issues disappear.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #22 on: July 18, 2014, 08:08:09 AM »
I've been setting up my server only w/ the -tcp option. I thought udp packets were sent on a randomized udp port and the -udp option was for lobby server stuff?

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #23 on: July 19, 2014, 12:52:14 PM »
If the server wasn't started with UDP, then UDP isn't going to be used at all. Only TCP will be used. When you try to use SendQuickly, it will go through TCP instead. If the server is started with -udp, then UDP will be used (provided the client is using it) when you use SendQuickly.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #24 on: July 21, 2014, 10:20:43 PM »
1. I'm still a little confused on TNTcpProtocol. It's used on both the server and client, but what functions are used on which ends? ProcessBuffer, OnReceive, Close all seem to be Client side functions. It seems like the clients send a Disconnect request packet to the server in the Close function. Can you go into a little bit more detail on this script?

2. If I wanted to build a separate app to monitor the server, channels, players, player actions, would it be better to do it in Unity or create another c# script like the TNet server?

3. I'm noticing that OnNetworkDisconnect() isn't called when I have a client connected to the server and then I close the server. The Close() function is called in TNTcpProtocol, but the OnNetworkDisconnect() doesn't seemed to be fired. Is that by design? Or am I missing something.

4. Would having multiple clients running on the same machine cause issues? Since they are both sharing the same TCP port on the client?
« Last Edit: July 22, 2014, 08:59:54 AM by gg67 »

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #25 on: July 22, 2014, 06:43:07 PM »
1. TcpProtocol is used on both client and server side. Client only has one of it, while the server has as many of them as there are players. Each player is a TcpProtocol instance. ProcessBuffer is the function that's used to receive incoming data. It's called from OnReceive right above it, which is an asynchronous callback triggered by the system when new data arrives. The process of gracefully closing the connection involves notifying the server by sending a packet. Otherwise the connection would be terminated abruptly.

2. I'd say C#.

3. I assume you mean manually closing the app without going through the 'q' to exit it? You get an error in this case on the client side ("An existing connection was forcibly closed by the remote host"). Although thinking about it, having it send OnNetworkDisconnect would make sense. I'll make it happen.

4. Clients don't use the same port. They use different ports, they just connect to the same server port. So multiple clients are fine.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #26 on: July 22, 2014, 06:58:53 PM »
For #3, I'm specifically talking about when the server tells the client to disconnect b/c the client sends a malformed packet. In this case I'd like to kick the user to my main menu screen. I assumed force closing the server gave me similar results on the client side. Is that gonna be the same thing?


ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #27 on: July 22, 2014, 08:05:42 PM »
Force closing the server just aborts the connection. It doesn't send anything, which is why there is no disconnect notification. I've modified the Pro repository to send out a notification. Will it affect your malformed packet case? Possibly, but it's just speculation on my part as I can't reproduce it on my end.

gg67

  • Jr. Member
  • **
  • Thank You
  • -Given: 0
  • -Receive: 0
  • Posts: 66
    • View Profile
Re: TNet/RFC Debugging
« Reply #28 on: July 22, 2014, 09:40:42 PM »
Awesome! Thanks.

As for the c# standalone server monitoring app, do we want to connect to the server as a client/player? Or do we want to create a modified server that tells us more info than the default one does?

I'm looking into the "connect as another player" design right now. Is this possible to do without any of the files in TNet/Client? (since those are all Unity dependent). Looks possible, but didn't know if there are any "gotchas" I should know about. For example, I was able to connect to a server using just TNTcpProtocol, but failed the verification since I didn't actually create a player and increase the static player count, etc.

What's the best approach?
« Last Edit: July 22, 2014, 11:40:08 PM by gg67 »

ArenMook

  • Administrator
  • Hero Member
  • *****
  • Thank You
  • -Given: 337
  • -Receive: 1171
  • Posts: 22,128
  • Toronto, Canada
    • View Profile
Re: TNet/RFC Debugging
« Reply #29 on: July 22, 2014, 11:48:49 PM »
Connecting as a player option would be much more powerful, letting you to remotely connect to the server from any app -- even a Unity application easily. Would it be better in your case, or would it make more sense to go down the more secure route with a dedicated connection? That's for you to decide. I'd go with the easier route, personally -- so the same route you're taking right now.

You will connect as a normal player, you just won't be joining any channels -- so the whole verification thing isn't an issue as it will happen automatically. No one will see you anyway.