Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(Logging): Added [KCP] to all log msgs #55

Merged
merged 2 commits into from
Nov 14, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -61,3 +61,5 @@ docs/.sass-cache
ehthumbs.db
Thumbs.db
/VisRepo.txt
/packages/NUnit.3.14.0
/packages.config
8 changes: 4 additions & 4 deletions kcp2k/kcp2k.Example/Program.cs
Original file line number Diff line number Diff line change
Expand Up @@ -42,18 +42,18 @@
// create server
KcpServer server = new KcpServer(
(connectionId) => {},
(connectionId, message, channel) => Log.Info($"KCP: OnServerDataReceived({connectionId}, {BitConverter.ToString(message.Array, message.Offset, message.Count)} @ {channel})"),
(connectionId, message, channel) => Log.Info($"[KCP] OnServerDataReceived({connectionId}, {BitConverter.ToString(message.Array, message.Offset, message.Count)} @ {channel})"),
(connectionId) => {},
(connectionId, error, reason) => Log.Error($"KCP: OnServerError({connectionId}, {error}, {reason}"),
(connectionId, error, reason) => Log.Error($"[KCP] OnServerError({connectionId}, {error}, {reason}"),
config
);

// create client
KcpClient client = new KcpClient(
() => {},
(message, channel) => Log.Info($"KCP: OnClientDataReceived({BitConverter.ToString(message.Array, message.Offset, message.Count)} @ {channel})"),
(message, channel) => Log.Info($"[KCP] OnClientDataReceived({BitConverter.ToString(message.Array, message.Offset, message.Count)} @ {channel})"),
() => {},
(error, reason) => Log.Warning($"KCP: OnClientError({error}, {reason}"),
(error, reason) => Log.Warning($"[KCP] OnClientError({error}, {reason}"),
config
);

Expand Down
14 changes: 7 additions & 7 deletions kcp2k/kcp2k.Tests/ClientServerTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -93,7 +93,7 @@ protected virtual void CreateServer()
(connectionId) => {},
ServerOnData,
(connectionId) => {},
(connectionId, error, reason) => Log.Warning($"connId={connectionId}: {error}, {reason}"),
(connectionId, error, reason) => Log.Warning($"[KCP] connId={connectionId}: {error}, {reason}"),
config
);
}
Expand All @@ -105,7 +105,7 @@ protected virtual void CreateClient()
() => {},
ClientOnData,
() => { ++onClientDisconnectCalled; },
(error, reason) => Log.Warning($"{error}, {reason}"),
(error, reason) => Log.Warning($"[KCP] {error}, {reason}"),
config
);
}
Expand Down Expand Up @@ -319,7 +319,7 @@ public void ClientToServerReliableMaxSizedMessage()
byte[] message = new byte[KcpPeer.ReliableMaxMessageSize(config.Mtu, config.ReceiveWindowSize)];
for (int i = 0; i < message.Length; ++i)
message[i] = (byte)(i & 0xFF);
Log.Info($"Sending {message.Length} bytes = {message.Length / 1024} KB message");
Log.Info($"[KCP] Sending {message.Length} bytes = {message.Length / 1024} KB message");
SendClientToServerBlocking(new ArraySegment<byte>(message), KcpChannel.Reliable);
UpdateSeveralTimes(5);
Assert.That(serverReceived.Count, Is.EqualTo(1));
Expand All @@ -337,7 +337,7 @@ public void ClientToServerUnreliableMaxSizedMessage()
byte[] message = new byte[KcpPeer.UnreliableMaxMessageSize(config.Mtu)];
for (int i = 0; i < message.Length; ++i)
message[i] = (byte)(i & 0xFF);
Log.Info($"Sending {message.Length} bytes = {message.Length / 1024} KB message");
Log.Info($"[KCP] Sending {message.Length} bytes = {message.Length / 1024} KB message");
SendClientToServerBlocking(new ArraySegment<byte>(message), KcpChannel.Unreliable);
Assert.That(serverReceived.Count, Is.EqualTo(1));
Assert.That(serverReceived[0].data.SequenceEqual(message), Is.True);
Expand All @@ -360,7 +360,7 @@ public void ClientToServerSlightlySmallerThanMTUSizedMessage(KcpChannel channel)
byte[] message = new byte[Kcp.MTU_DEF - 5];
for (int i = 0; i < message.Length; ++i)
message[i] = (byte)(i & 0xFF);
Log.Info($"Sending {message.Length} bytes = {message.Length / 1024} KB message");
Log.Info($"[KCP] Sending {message.Length} bytes = {message.Length / 1024} KB message");
SendClientToServerBlocking(new ArraySegment<byte>(message), channel);
Assert.That(serverReceived.Count, Is.EqualTo(1));
Assert.That(serverReceived[0].data.SequenceEqual(message), Is.True);
Expand Down Expand Up @@ -877,7 +877,7 @@ public void TimeoutIsResetByMessage(KcpChannel channel)

// sleep for half a timeout
int firstSleep = config.Timeout / 2;
Log.Info($"sleeping for {firstSleep} ms...");
Log.Info($"[KCP] sleeping for {firstSleep} ms...");
Thread.Sleep(firstSleep);

// send one reliable message to both ends
Expand All @@ -891,7 +891,7 @@ public void TimeoutIsResetByMessage(KcpChannel channel)
// sleep for half a timeout again.
// use exactly the remainder instead of '/2' so nothing gets lost
int lastSleep = config.Timeout - firstSleep + 1;
Log.Info($"sleeping for {lastSleep} ms...");
Log.Info($"[KCP] sleeping for {lastSleep} ms...");
Thread.Sleep(lastSleep);

// should still be connected
Expand Down
6 changes: 3 additions & 3 deletions kcp2k/kcp2k.Tests/MultiClientServerTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,7 @@ protected virtual void CreateServer()
(connectionId) => {},
ServerOnData,
(connectionId) => {},
(connectionId, error, reason) => Log.Warning($"connId={connectionId}: {error}, {reason}"),
(connectionId, error, reason) => Log.Warning($"[KCP] connId={connectionId}: {error}, {reason}"),
config
);
}
Expand All @@ -103,14 +103,14 @@ protected virtual void CreateClients()
() => {},
ClientOnDataA,
() => {},
(error, reason) => Log.Warning($"A: {error}, {reason}"),
(error, reason) => Log.Warning($"[KCP] A: {error}, {reason}"),
config
);
clientB = new KcpClient(
() => {},
ClientOnDataB,
() => {},
(error, reason) => Log.Warning($"B: {error}, {reason}"),
(error, reason) => Log.Warning($"[KCP] B: {error}, {reason}"),
config
);
}
Expand Down
6 changes: 3 additions & 3 deletions kcp2k/kcp2k/highlevel/Common.cs
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ public static bool ResolveHostname(string hostname, out IPAddress[] addresses)
}
catch (SocketException exception)
{
Log.Info($"Failed to resolve host: {hostname} reason: {exception}");
Log.Info($"[KCP] Failed to resolve host: {hostname} reason: {exception}");
addresses = null;
return false;
}
Expand All @@ -41,11 +41,11 @@ public static void ConfigureSocketBuffers(Socket socket, int recvBufferSize, int
}
catch (SocketException)
{
Log.Warning($"Kcp: failed to set Socket RecvBufSize = {recvBufferSize} SendBufSize = {sendBufferSize}");
Log.Warning($"[KCP] failed to set Socket RecvBufSize = {recvBufferSize} SendBufSize = {sendBufferSize}");
}


Log.Info($"Kcp: RecvBuf = {initialReceive}=>{socket.ReceiveBufferSize} ({socket.ReceiveBufferSize/initialReceive}x) SendBuf = {initialSend}=>{socket.SendBufferSize} ({socket.SendBufferSize/initialSend}x)");
Log.Info($"[KCP] RecvBuf = {initialReceive}=>{socket.ReceiveBufferSize} ({socket.ReceiveBufferSize/initialReceive}x) SendBuf = {initialSend}=>{socket.SendBufferSize} ({socket.SendBufferSize/initialSend}x)");
}

// generate a connection hash from IP+Port.
Expand Down
22 changes: 11 additions & 11 deletions kcp2k/kcp2k/highlevel/KcpClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@ public KcpClient(Action OnConnected,
// some callbacks need to wrapped with some extra logic
protected override void OnAuthenticated()
{
Log.Info($"KcpClient: OnConnected");
Log.Info($"[KCP] Client: OnConnected");
connected = true;
OnConnectedCallback();
}
Expand All @@ -78,7 +78,7 @@ protected override void OnError(ErrorCode error, string message) =>

protected override void OnDisconnected()
{
Log.Info($"KcpClient: OnDisconnected");
Log.Info($"[KCP] Client: OnDisconnected");
connected = false;
socket?.Close();
socket = null;
Expand All @@ -92,7 +92,7 @@ public void Connect(string address, ushort port)
{
if (connected)
{
Log.Warning("KcpClient: already connected!");
Log.Warning("[KCP] Client: already connected!");
return;
}

Expand All @@ -110,7 +110,7 @@ public void Connect(string address, ushort port)
// client doesn't need secure cookie.
Reset(config);

Log.Info($"KcpClient: connect to {address}:{port}");
Log.Info($"[KCP] Client: connect to {address}:{port}");

// create socket
remoteEndPoint = new IPEndPoint(addresses[0], port);
Expand Down Expand Up @@ -156,7 +156,7 @@ protected virtual bool RawReceive(out ArraySegment<byte> segment)
// at least log a message for easier debugging.
// for example, his can happen when connecting without a server.
// see test: ConnectWithoutServer().
Log.Info($"KcpClient: looks like the other end has closed the connection. This is fine: {e}");
Log.Info($"[KCP] Client: looks like the other end has closed the connection. This is fine: {e}");
base.Disconnect();
return false;
}
Expand All @@ -172,15 +172,15 @@ protected override void RawSend(ArraySegment<byte> data)
}
catch (SocketException e)
{
Log.Error($"KcpClient: Send failed: {e}");
Log.Error($"[KCP] Client: Send failed: {e}");
}
}

public void Send(ArraySegment<byte> segment, KcpChannel channel)
{
if (!connected)
{
Log.Warning("KcpClient: can't send because not connected!");
Log.Warning("[KCP] Client: can't send because not connected!");
return;
}

Expand Down Expand Up @@ -217,17 +217,17 @@ public void RawInput(ArraySegment<byte> segment)
Utils.Decode32U(segment.Array, segment.Offset + 1, out uint messageCookie);
if (messageCookie == 0)
{
Log.Error($"KcpClient: received message with cookie=0, this should never happen. Server should always include the security cookie.");
Log.Error($"[KCP] Client: received message with cookie=0, this should never happen. Server should always include the security cookie.");
}

if (cookie == 0)
{
cookie = messageCookie;
Log.Info($"KcpClient: received initial cookie: {cookie}");
Log.Info($"[KCP] Client: received initial cookie: {cookie}");
}
else if (cookie != messageCookie)
{
Log.Warning($"KcpClient: dropping message with mismatching cookie: {messageCookie} expected: {cookie}.");
Log.Warning($"[KCP] Client: dropping message with mismatching cookie: {messageCookie} expected: {cookie}.");
return;
}

Expand All @@ -251,7 +251,7 @@ public void RawInput(ArraySegment<byte> segment)
// invalid channel indicates random internet noise.
// servers may receive random UDP data.
// just ignore it, but log for easier debugging.
Log.Warning($"KcpClient: invalid channel header: {channel}, likely internet noise");
Log.Warning($"[KCP] Client: invalid channel header: {channel}, likely internet noise");
break;
}
}
Expand Down
18 changes: 9 additions & 9 deletions kcp2k/kcp2k/highlevel/KcpPeer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -153,7 +153,7 @@ protected KcpPeer(KcpConfig config, uint cookie)
// set the cookie after resetting state so it's not overwritten again.
// with log message for debugging in case of cookie issues.
this.cookie = cookie;
Log.Info($"{GetType()}: created with cookie={cookie}");
Log.Info($"[KCP] {GetType()}: created with cookie={cookie}");

// create mtu sized send buffer
rawSendBuffer = new byte[config.Mtu];
Expand Down Expand Up @@ -246,7 +246,7 @@ void HandlePing(uint time)
if (time >= lastPingTime + PING_INTERVAL)
{
// ping again and reset time
//Log.Debug("KCP: sending ping...");
//Log.Debug("[KCP] sending ping...");
SendPing();
lastPingTime = time;
}
Expand Down Expand Up @@ -340,7 +340,7 @@ void TickIncoming_Connected(uint time)
// it proves that the other end speaks our protocol.

// log with previously parsed cookie
Log.Info($"{GetType()}: received hello with cookie={cookie}");
Log.Info($"[KCP] {GetType()}: received hello with cookie={cookie}");
state = KcpState.Authenticated;
OnAuthenticated();
break;
Expand All @@ -356,7 +356,7 @@ void TickIncoming_Connected(uint time)
// everything else is not allowed during handshake!
// pass error to user callback. no need to log it manually.
// GetType() shows Server/ClientConn instead of just Connection.
OnError(ErrorCode.InvalidReceive, $"{GetType()}: received invalid header {header} while Connected. Disconnecting the connection.");
OnError(ErrorCode.InvalidReceive, $"[KCP] {GetType()}: received invalid header {header} while Connected. Disconnecting the connection.");
Disconnect();
break;
}
Expand Down Expand Up @@ -413,7 +413,7 @@ void TickIncoming_Authenticated(uint time)
{
// disconnect might happen
// GetType() shows Server/ClientConn instead of just Connection.
Log.Info($"{GetType()}: received disconnect message");
Log.Info($"[KCP] {GetType()}: received disconnect message");
Disconnect();
break;
}
Expand Down Expand Up @@ -529,7 +529,7 @@ protected void OnRawInputReliable(ArraySegment<byte> message)
if (input != 0)
{
// GetType() shows Server/ClientConn instead of just Connection.
Log.Warning($"{GetType()}: Input failed with error={input} for buffer with length={message.Count - 1}");
Log.Warning($"[KCP] {GetType()}: Input failed with error={input} for buffer with length={message.Count - 1}");
}
}

Expand Down Expand Up @@ -638,7 +638,7 @@ void SendUnreliable(ArraySegment<byte> message)
{
// otherwise content is larger than MaxMessageSize. let user know!
// GetType() shows Server/ClientConn instead of just Connection.
Log.Error($"{GetType()}: Failed to send unreliable message of size {message.Count} because it's larger than UnreliableMaxMessageSize={unreliableMax}");
Log.Error($"[KCP] {GetType()}: Failed to send unreliable message of size {message.Count} because it's larger than UnreliableMaxMessageSize={unreliableMax}");
return;
}

Expand Down Expand Up @@ -671,7 +671,7 @@ public void SendHello()
// cookie is automatically included in all messages.

// GetType() shows Server/ClientConn instead of just Connection.
Log.Info($"{GetType()}: sending handshake to other end with cookie={cookie}");
Log.Info($"[KCP] {GetType()}: sending handshake to other end with cookie={cookie}");
SendReliable(KcpHeader.Hello, default);
}

Expand Down Expand Up @@ -738,7 +738,7 @@ public virtual void Disconnect()

// set as Disconnected, call event
// GetType() shows Server/ClientConn instead of just Connection.
Log.Info($"{GetType()}: Disconnected.");
Log.Info($"[KCP] {GetType()}: Disconnected.");
state = KcpState.Disconnected;
OnDisconnected();
}
Expand Down
18 changes: 9 additions & 9 deletions kcp2k/kcp2k/highlevel/KcpServer.cs
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,7 @@ static Socket CreateServerSocket(bool DualMode, ushort port)
}
catch (NotSupportedException e)
{
Log.Warning($"Failed to set Dual Mode, continuing with IPv6 without Dual Mode. Error: {e}");
Log.Warning($"[KCP] Failed to set Dual Mode, continuing with IPv6 without Dual Mode. Error: {e}");
}

// for windows sockets, there's a rare issue where when using
Expand Down Expand Up @@ -151,7 +151,7 @@ public virtual void Start(ushort port)
// only start once
if (socket != null)
{
Log.Warning("KcpServer: already started!");
Log.Warning("[KCP] Server: already started!");
return;
}

Expand Down Expand Up @@ -219,7 +219,7 @@ protected virtual bool RawReceiveFrom(out ArraySegment<byte> segment, out int co
// the other end closing the connection is not an 'error'.
// but connections should never just end silently.
// at least log a message for easier debugging.
Log.Info($"KcpServer: ReceiveFrom failed: {e}");
Log.Info($"[KCP] Server: ReceiveFrom failed: {e}");
}

return false;
Expand All @@ -233,7 +233,7 @@ protected virtual void RawSend(int connectionId, ArraySegment<byte> data)
// get the connection's endpoint
if (!connections.TryGetValue(connectionId, out KcpServerConnection connection))
{
Log.Warning($"KcpServer: RawSend invalid connectionId={connectionId}");
Log.Warning($"[KCP] Server: RawSend invalid connectionId={connectionId}");
return;
}

Expand All @@ -243,7 +243,7 @@ protected virtual void RawSend(int connectionId, ArraySegment<byte> data)
}
catch (SocketException e)
{
Log.Error($"KcpServer: SendTo failed: {e}");
Log.Error($"[KCP] Server: SendTo failed: {e}");
}
}

Expand Down Expand Up @@ -274,7 +274,7 @@ void OnConnectedCallback(KcpServerConnection conn)
{
// add to connections dict after being authenticated.
connections.Add(connectionId, conn);
Log.Info($"KcpServer: added connection({connectionId})");
Log.Info($"[KCP] Server: added connection({connectionId})");

// setup Data + Disconnected events only AFTER the
// handshake. we don't want to fire OnServerDisconnected
Expand All @@ -284,7 +284,7 @@ void OnConnectedCallback(KcpServerConnection conn)
// setup data event

// finally, call mirror OnConnected event
Log.Info($"KcpServer: OnConnected({connectionId})");
Log.Info($"[KCP] Server: OnConnected({connectionId})");
OnConnected(connectionId);
}

Expand All @@ -296,7 +296,7 @@ void OnDisconnectedCallback()
connectionsToRemove.Add(connectionId);

// call mirror event
Log.Info($"KcpServer: OnDisconnected({connectionId})");
Log.Info($"[KCP] Server: OnDisconnected({connectionId})");
OnDisconnected(connectionId);
}
}
Expand All @@ -305,7 +305,7 @@ void OnDisconnectedCallback()
// best to call this as long as there is more data to receive.
void ProcessMessage(ArraySegment<byte> segment, int connectionId)
{
//Log.Info($"KCP: server raw recv {msgLength} bytes = {BitConverter.ToString(buffer, 0, msgLength)}");
//Log.Info($"[KCP] server raw recv {msgLength} bytes = {BitConverter.ToString(buffer, 0, msgLength)}");

// is this a new connection?
if (!connections.TryGetValue(connectionId, out KcpServerConnection connection))
Expand Down
Loading