feat(SWT): Logging System Overhaul (#3663)

* SWT-Logging system overhaul
This commit is contained in:
MrGadget 2023-11-24 17:39:23 -05:00 committed by GitHub
parent bfe95afc0c
commit dfec9a713e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
16 changed files with 245 additions and 182 deletions

View File

@ -97,7 +97,7 @@ public void ProcessMessageQueue(MonoBehaviour behaviour)
} }
} }
if (receiveQueue.Count > 0) if (receiveQueue.Count > 0)
Log.Warn($"SimpleWebClient ProcessMessageQueue has {receiveQueue.Count} remaining."); Log.Warn($"[SWT-SimpleWebClient]: ProcessMessageQueue has {receiveQueue.Count} remaining.");
} }
} }
} }

View File

@ -24,7 +24,7 @@ public bool TryHandshake(Connection conn, Uri uri)
string key = Convert.ToBase64String(keyBuffer); string key = Convert.ToBase64String(keyBuffer);
string keySum = key + Constants.HandshakeGUID; string keySum = key + Constants.HandshakeGUID;
byte[] keySumBytes = Encoding.ASCII.GetBytes(keySum); byte[] keySumBytes = Encoding.ASCII.GetBytes(keySum);
Log.Verbose($"[SimpleWebTransport] Handshake Hashing {Encoding.ASCII.GetString(keySumBytes)}"); Log.Verbose($"[SWT-ClientHandshake]: Handshake Hashing {Encoding.ASCII.GetString(keySumBytes)}");
// SHA-1 is the websocket standard: // SHA-1 is the websocket standard:
// https://www.rfc-editor.org/rfc/rfc6455 // https://www.rfc-editor.org/rfc/rfc6455
@ -50,19 +50,19 @@ public bool TryHandshake(Connection conn, Uri uri)
if (!lengthOrNull.HasValue) if (!lengthOrNull.HasValue)
{ {
Log.Error("[SimpleWebTransport] Connection closed before handshake"); Log.Error("[SWT-ClientHandshake]: Connection closed before handshake");
return false; return false;
} }
string responseString = Encoding.ASCII.GetString(responseBuffer, 0, lengthOrNull.Value); string responseString = Encoding.ASCII.GetString(responseBuffer, 0, lengthOrNull.Value);
Log.Verbose($"[SimpleWebTransport] Handshake Response {responseString}"); Log.Verbose($"[SWT-ClientHandshake]: Handshake Response {responseString}");
string acceptHeader = "Sec-WebSocket-Accept: "; string acceptHeader = "Sec-WebSocket-Accept: ";
int startIndex = responseString.IndexOf(acceptHeader, StringComparison.InvariantCultureIgnoreCase); int startIndex = responseString.IndexOf(acceptHeader, StringComparison.InvariantCultureIgnoreCase);
if (startIndex < 0) if (startIndex < 0)
{ {
Log.Error($"[SimpleWebTransport] Unexpected Handshake Response {responseString}"); Log.Error($"[SWT-ClientHandshake]: Unexpected Handshake Response {responseString}");
return false; return false;
} }
@ -72,7 +72,7 @@ public bool TryHandshake(Connection conn, Uri uri)
if (responseKey != expectedResponse) if (responseKey != expectedResponse)
{ {
Log.Error($"[SimpleWebTransport] Response key incorrect\nResponse:{responseKey}\nExpected:{expectedResponse}"); Log.Error($"[SWT-ClientHandshake]: Response key incorrect\nResponse:{responseKey}\nExpected:{expectedResponse}");
return false; return false;
} }

View File

@ -24,7 +24,7 @@ internal bool TryCreateStream(Connection conn, Uri uri)
} }
catch (Exception e) catch (Exception e)
{ {
Log.Error($"[SimpleWebTransport] Create SSLStream Failed: {e}", false); Log.Error($"[SWT-ClientSslHelper]: Create SSLStream Failed: {e.Message}\n{e.StackTrace}\n\n");
return false; return false;
} }
} }

View File

@ -60,7 +60,7 @@ void ConnectAndReceiveLoop(Uri serverAddress)
bool success = sslHelper.TryCreateStream(conn, serverAddress); bool success = sslHelper.TryCreateStream(conn, serverAddress);
if (!success) if (!success)
{ {
Log.Warn($"[SimpleWebTransport] Failed to create Stream with {serverAddress}"); Log.Warn($"[SWT-WebSocketClientStandAlone]: Failed to create Stream with {serverAddress}");
conn.Dispose(); conn.Dispose();
return; return;
} }
@ -68,12 +68,12 @@ void ConnectAndReceiveLoop(Uri serverAddress)
success = handshake.TryHandshake(conn, serverAddress); success = handshake.TryHandshake(conn, serverAddress);
if (!success) if (!success)
{ {
Log.Warn($"[SimpleWebTransport] Failed Handshake with {serverAddress}"); Log.Warn($"[SWT-WebSocketClientStandAlone]: Failed Handshake with {serverAddress}");
conn.Dispose(); conn.Dispose();
return; return;
} }
Log.Info($"[SimpleWebTransport] HandShake Successful with {serverAddress}"); Log.Info($"[SWT-WebSocketClientStandAlone]: HandShake Successful with {serverAddress}");
state = ClientState.Connected; state = ClientState.Connected;
@ -120,7 +120,7 @@ void AfterConnectionDisposed(Connection conn)
public override void Disconnect() public override void Disconnect()
{ {
state = ClientState.Disconnecting; state = ClientState.Disconnecting;
Log.Info("[SimpleWebTransport] Disconnect Called"); Log.Verbose("[SWT-WebSocketClientStandAlone]: Disconnect Called");
if (conn == null) if (conn == null)
state = ClientState.NotConnected; state = ClientState.NotConnected;

View File

@ -76,7 +76,7 @@ public override void Send(ArraySegment<byte> segment)
{ {
if (segment.Count > maxMessageSize) if (segment.Count > maxMessageSize)
{ {
Log.Error($"[SimpleWebTransport] Cant send message with length {segment.Count} because it is over the max size of {maxMessageSize}"); Log.Error($"[SWT-WebSocketClientWebGl]: Cant send message with length {segment.Count} because it is over the max size of {maxMessageSize}");
return; return;
} }
@ -128,7 +128,7 @@ void onMessage(IntPtr bufferPtr, int count)
} }
catch (Exception e) catch (Exception e)
{ {
Log.Error($"[SimpleWebTransport] onMessage {e.GetType()}: {e.Message}\n{e.StackTrace}"); Log.Error($"[SWT-WebSocketClientWebGl]: onMessage {e.GetType()}: {e.Message}\n{e.StackTrace}");
receiveQueue.Enqueue(new Message(e)); receiveQueue.Enqueue(new Message(e));
} }
} }

View File

@ -97,7 +97,7 @@ public void CopyFrom(IntPtr bufferPtr, int length)
internal void Validate(int arraySize) internal void Validate(int arraySize)
{ {
if (array.Length != arraySize) if (array.Length != arraySize)
Log.Error("[SimpleWebTransport] Buffer that was returned had an array of the wrong size"); Log.Error("[SWT-ArrayBuffer]: Buffer that was returned had an array of the wrong size");
} }
} }
@ -124,7 +124,7 @@ public ArrayBuffer Take()
return buffer; return buffer;
else else
{ {
Log.Verbose($"[SimpleWebTransport] BufferBucket({arraySize}) create new"); Log.Flood($"[SWT-BufferBucket]: BufferBucket({arraySize}) create new");
return new ArrayBuffer(this, arraySize); return new ArrayBuffer(this, arraySize);
} }
} }
@ -140,13 +140,14 @@ public void Return(ArrayBuffer buffer)
void IncrementCreated() void IncrementCreated()
{ {
int next = Interlocked.Increment(ref _current); int next = Interlocked.Increment(ref _current);
Log.Verbose($"[SimpleWebTransport] BufferBucket({arraySize}) count:{next}"); Log.Flood($"[SWT-BufferBucket]: BufferBucket({arraySize}) count:{next}");
} }
[Conditional("DEBUG")] [Conditional("DEBUG")]
void DecrementCreated() void DecrementCreated()
{ {
int next = Interlocked.Decrement(ref _current); int next = Interlocked.Decrement(ref _current);
Log.Verbose($"[SimpleWebTransport] BufferBucket({arraySize}) count:{next}"); Log.Flood($"[SWT-BufferBucket]: BufferBucket({arraySize}) count:{next}");
} }
} }
@ -225,12 +226,12 @@ public BufferPool(int bucketCount, int smallest, int largest)
void Validate() void Validate()
{ {
if (buckets[0].arraySize != smallest) if (buckets[0].arraySize != smallest)
Log.Error($"[SimpleWebTransport] BufferPool Failed to create bucket for smallest. bucket:{buckets[0].arraySize} smallest{smallest}"); Log.Error($"[SWT-BufferPool]: BufferPool Failed to create bucket for smallest. bucket:{buckets[0].arraySize} smallest:{smallest}");
int largestBucket = buckets[bucketCount - 1].arraySize; int largestBucket = buckets[bucketCount - 1].arraySize;
// rounded using Ceiling, so allowed to be 1 more that largest // rounded using Ceiling, so allowed to be 1 more that largest
if (largestBucket != largest && largestBucket != largest + 1) if (largestBucket != largest && largestBucket != largest + 1)
Log.Error($"[SimpleWebTransport] BufferPool Failed to create bucket for largest. bucket:{largestBucket} smallest{largest}"); Log.Error($"[SWT-BufferPool]: BufferPool Failed to create bucket for largest. bucket:{largestBucket} smallest:{largest}");
} }
public ArrayBuffer Take(int size) public ArrayBuffer Take(int size)

View File

@ -48,12 +48,12 @@ public Connection(TcpClient client, Action<Connection> onDispose)
/// </summary> /// </summary>
public void Dispose() public void Dispose()
{ {
Log.Verbose($"[SimpleWebTransport] Dispose {ToString()}"); Log.Verbose($"[SWT-Connection]: Dispose {ToString()}");
// check hasDisposed first to stop ThreadInterruptedException on lock // check hasDisposed first to stop ThreadInterruptedException on lock
if (hasDisposed) return; if (hasDisposed) return;
Log.Info($"[SimpleWebTransport] Connection Close: {ToString()}"); Log.Verbose($"[SWT-Connection]: Connection Close: {ToString()}");
lock (disposedLock) lock (disposedLock)
{ {
@ -91,6 +91,7 @@ public void Dispose()
public override string ToString() public override string ToString()
{ {
// remoteAddress isn't set until after handshake
if (hasDisposed) if (hasDisposed)
return $"[Conn:{connId}, Disposed]"; return $"[Conn:{connId}, Disposed]";
else if (!string.IsNullOrWhiteSpace(remoteAddress)) else if (!string.IsNullOrWhiteSpace(remoteAddress))

View File

@ -41,91 +41,184 @@ public enum Levels
public static ILogger logger = Debug.unityLogger; public static ILogger logger = Debug.unityLogger;
public static Levels minLogLevel = Levels.None; public static Levels minLogLevel = Levels.None;
public static string BufferToString(byte[] buffer, int offset = 0, int? length = null) /// <summary>
{ /// Logs all exceptions to console
return BitConverter.ToString(buffer, offset, length ?? buffer.Length); /// </summary>
} /// <param name="e">Exception to log</param>
public static void DumpBuffer(string label, byte[] buffer, int offset, int length)
{
if (minLogLevel < Levels.Verbose)
return;
logger.Log(LogType.Log, $"[SimpleWebTransport] VERBOSE: <color=cyan>{label}: {BufferToString(buffer, offset, length)}</color>");
}
public static void DumpBuffer(string label, ArrayBuffer arrayBuffer)
{
if (minLogLevel < Levels.Verbose)
return;
logger.Log(LogType.Log, $"[SimpleWebTransport] VERBOSE: <color=cyan>{label}: {BufferToString(arrayBuffer.array, 0, arrayBuffer.count)}</color>");
}
public static void Verbose(string msg, bool showColor = true)
{
if (minLogLevel < Levels.Verbose)
return;
if (showColor)
logger.Log(LogType.Log, $"[SimpleWebTransport] VERBOSE: <color=cyan>{msg}</color>");
else
logger.Log(LogType.Log, $"[SimpleWebTransport] VERBOSE: {msg}");
}
public static void Info(string msg, bool showColor = true)
{
if (minLogLevel < Levels.Info)
return;
if (showColor)
logger.Log(LogType.Log, $"[SimpleWebTransport] INFO: <color=cyan>{msg}</color>");
else
logger.Log(LogType.Log, $"[SimpleWebTransport] INFO: {msg}");
}
public static void InfoException(Exception e)
{
if (minLogLevel < Levels.Info)
return;
#if UNITY_SERVER
logger.Log(LogType.Log, $"[SimpleWebTransport] INFO_EXCEPTION: {e.GetType().Name} Message: {e.Message}\n{e.StackTrace}\n\n");
#else
logger.Log(LogType.Log, $"[SimpleWebTransport] INFO_EXCEPTION: <color=cyan>{e.GetType().Name}</color> Message: {e.Message}\n{e.StackTrace}\n\n");
#endif
}
public static void Warn(string msg, bool showColor = true)
{
if (minLogLevel < Levels.Warn)
return;
if (showColor)
logger.Log(LogType.Warning, $"[SimpleWebTransport] WARN: <color=orange>{msg}</color>");
else
logger.Log(LogType.Warning, $"[SimpleWebTransport] WARN: {msg}");
}
public static void Error(string msg, bool showColor = true)
{
if (minLogLevel < Levels.Error)
return;
if (showColor)
logger.Log(LogType.Error, $"[SimpleWebTransport] ERROR: <color=red>{msg}</color>");
else
logger.Log(LogType.Error, $"[SimpleWebTransport] ERROR: {msg}");
}
public static void Exception(Exception e) public static void Exception(Exception e)
{ {
// always log Exceptions #if UNITY_SERVER || UNITY_WEBGL
#if UNITY_SERVER Console.ForegroundColor = ConsoleColor.Red;
logger.Log(LogType.Error, $"[SimpleWebTransport] EXCEPTION: {e.GetType().Name} Message: {e.Message}\n{e.StackTrace}\n\n"); Console.WriteLine($"[SWT:Exception] {e.GetType().Name}: {e.Message}\n{e.StackTrace}\n\n");
Console.ResetColor();
#else #else
logger.Log(LogType.Error, $"[SimpleWebTransport] EXCEPTION: <color=red>{e.GetType().Name}</color> Message: {e.Message}\n{e.StackTrace}\n\n"); logger.Log(LogType.Exception, $"[SWT:Exception] {e.GetType().Name}: {e.Message}\n{e.StackTrace}\n\n");
#endif #endif
} }
/// <summary>
/// Logs flood to console if minLogLevel is set to Flood or lower
/// </summary>
/// <param name="msg">Message text to log</param>
[Conditional("DEBUG")]
public static void Flood(string msg)
{
if (minLogLevel > Levels.Flood) return;
#if UNITY_SERVER || UNITY_WEBGL
Console.ForegroundColor = ConsoleColor.Gray;
logger.Log(LogType.Log, msg);
Console.ResetColor();
#else
logger.Log(LogType.Log, msg);
#endif
}
/// <summary>
/// Logs buffer to console if minLogLevel is set to Flood or lower
/// <para>Debug mode requrired, e.g. Unity Editor of Develpment Build</para>
/// </summary>
/// <param name="label">Source of the log message</param>
/// <param name="buffer">Byte array to be logged</param>
/// <param name="offset">starting point of byte array</param>
/// <param name="length">number of bytes to read</param>
[Conditional("DEBUG")]
public static void DumpBuffer(string label, byte[] buffer, int offset, int length)
{
if (minLogLevel > Levels.Flood) return;
#if UNITY_SERVER || UNITY_WEBGL
Console.ForegroundColor = ConsoleColor.DarkBlue;
logger.Log(LogType.Log, $"{label}: {BufferToString(buffer, offset, length)}");
Console.ResetColor();
#else
logger.Log(LogType.Log, $"<color=cyan>{label}: {BufferToString(buffer, offset, length)}</color>");
#endif
}
/// <summary>
/// Logs buffer to console if minLogLevel is set to Flood or lower
/// <para>Debug mode requrired, e.g. Unity Editor of Develpment Build</para>
/// </summary>
/// <param name="label">Source of the log message</param>
/// <param name="arrayBuffer">ArrayBuffer to show details for</param>
[Conditional("DEBUG")]
public static void DumpBuffer(string label, ArrayBuffer arrayBuffer)
{
if (minLogLevel > Levels.Flood) return;
#if UNITY_SERVER || UNITY_WEBGL
Console.ForegroundColor = ConsoleColor.DarkBlue;
logger.Log(LogType.Log, $"{label}: {BufferToString(arrayBuffer.array, 0, arrayBuffer.count)}");
Console.ResetColor();
#else
logger.Log(LogType.Log, $"<color=cyan>{label}: {BufferToString(arrayBuffer.array, 0, arrayBuffer.count)}</color>");
#endif
}
/// <summary>
/// Logs verbose to console if minLogLevel is set to Verbose or lower
/// </summary>
/// <param name="msg">Message text to log</param>
public static void Verbose(string msg)
{
if (minLogLevel > Levels.Verbose) return;
#if DEBUG
// Debug builds and Unity Editor
logger.Log(LogType.Log, msg);
#else
// Server or WebGL
Console.ForegroundColor = ConsoleColor.Blue;
Console.WriteLine(msg);
Console.ResetColor();
#endif
}
/// <summary>
/// Logs info to console if minLogLevel is set to Info or lower
/// </summary>
/// <param name="msg">Message text to log</param>
/// <param name="consoleColor">Default Cyan works in server and browser consoles</param>
public static void Info(string msg, ConsoleColor consoleColor = ConsoleColor.Cyan)
{
if (minLogLevel > Levels.Info) return;
#if DEBUG
// Debug builds and Unity Editor
logger.Log(LogType.Log, msg);
#else
// Server or WebGL
Console.ForegroundColor = consoleColor;
Console.WriteLine(msg);
Console.ResetColor();
#endif
}
/// <summary>
/// Logs info to console if minLogLevel is set to Info or lower
/// </summary>
/// <param name="e">Exception to log</param>
public static void InfoException(Exception e)
{
if (minLogLevel > Levels.Info) return;
#if DEBUG
// Debug builds and Unity Editor
logger.Log(LogType.Exception, e.Message);
#else
// Server or WebGL
Console.ForegroundColor = ConsoleColor.DarkRed;
Console.WriteLine(e.Message);
Console.ResetColor();
#endif
}
/// <summary>
/// Logs info to console if minLogLevel is set to Warn or lower
/// </summary>
/// <param name="msg">Message text to log</param>
public static void Warn(string msg)
{
if (minLogLevel > Levels.Warn) return;
#if DEBUG
// Debug builds and Unity Editor
logger.Log(LogType.Warning, msg);
#else
// Server or WebGL
Console.ForegroundColor = ConsoleColor.Yellow;
Console.WriteLine(msg);
Console.ResetColor();
#endif
}
/// <summary>
/// Logs info to console if minLogLevel is set to Error or lower
/// </summary>
/// <param name="msg">Message text to log</param>
public static void Error(string msg)
{
if (minLogLevel > Levels.Error) return;
#if DEBUG
// Debug builds and Unity Editor
logger.Log(LogType.Error, msg);
#else
// Server or WebGL
Console.ForegroundColor = ConsoleColor.Red;
Console.WriteLine(msg);
Console.ResetColor();
#endif
}
/// <summary>
/// Returns a string representation of the byte array starting from offset for length bytes
/// </summary>
/// <param name="buffer">Byte array to read</param>
/// <param name="offset">starting point in the byte array</param>
/// <param name="length">number of bytes to read from offset</param>
/// <returns></returns>
public static string BufferToString(byte[] buffer, int offset = 0, int? length = null) => BitConverter.ToString(buffer, offset, length ?? buffer.Length);
} }
} }

View File

@ -80,7 +80,7 @@ public static bool TryRead(Stream stream, byte[] outBuffer, int outOffset, int l
if (read >= maxLength) if (read >= maxLength)
{ {
Log.Error("[SimpleWebTransport] SafeReadTillMatch exceeded maxLength"); Log.Error("[SWT-ReadHelper]: SafeReadTillMatch exceeded maxLength");
return null; return null;
} }

View File

@ -62,7 +62,7 @@ public static void Loop(Config config)
while (client.Connected) while (client.Connected)
ReadOneMessage(config, readBuffer); ReadOneMessage(config, readBuffer);
Log.Info($"[SimpleWebTransport] {conn} Not Connected"); Log.Verbose($"[SWT-ReceiveLoop]: {conn} Not Connected");
} }
catch (Exception) catch (Exception)
{ {
@ -81,18 +81,18 @@ public static void Loop(Config config)
catch (SocketException e) catch (SocketException e)
{ {
// this could happen if wss client closes stream // this could happen if wss client closes stream
Log.Warn($"[SimpleWebTransport] ReceiveLoop SocketException\n{e.Message}", false); Log.Warn($"[SWT-ReceiveLoop]: ReceiveLoop SocketException\n{e.Message}");
queue.Enqueue(new Message(conn.connId, e)); queue.Enqueue(new Message(conn.connId, e));
} }
catch (IOException e) catch (IOException e)
{ {
// this could happen if client disconnects // this could happen if client disconnects
Log.Warn($"[SimpleWebTransport] ReceiveLoop IOException\n{e.Message}", false); Log.Warn($"[SWT-ReceiveLoop]: ReceiveLoop IOException\n{e.Message}");
queue.Enqueue(new Message(conn.connId, e)); queue.Enqueue(new Message(conn.connId, e));
} }
catch (InvalidDataException e) catch (InvalidDataException e)
{ {
Log.Error($"[SimpleWebTransport] Invalid data from {conn}: {e.Message}"); Log.Error($"[SWT-ReceiveLoop]: Invalid data from {conn}\n{e.Message}\n{e.StackTrace}\n\n");
queue.Enqueue(new Message(conn.connId, e)); queue.Enqueue(new Message(conn.connId, e));
} }
catch (Exception e) catch (Exception e)
@ -161,7 +161,7 @@ static void ReadOneMessage(Config config, byte[] buffer)
} }
// dump after mask off // dump after mask off
Log.DumpBuffer($"[SimpleWebTransport] Message", msg); Log.DumpBuffer($"[SWT-ReceiveLoop]: Message", msg);
queue.Enqueue(new Message(conn.connId, msg)); queue.Enqueue(new Message(conn.connId, msg));
} }
@ -176,14 +176,14 @@ static Header ReadHeader(Config config, byte[] buffer, bool opCodeContinuation =
// read 2 // read 2
header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.HeaderMinSize); header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.HeaderMinSize);
// log after first blocking call // log after first blocking call
Log.Verbose($"[SimpleWebTransport] Message From {conn}"); Log.Flood($"[SWT-ReceiveLoop]: Message From {conn}");
if (MessageProcessor.NeedToReadShortLength(buffer)) if (MessageProcessor.NeedToReadShortLength(buffer))
header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.ShortLength); header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.ShortLength);
if (MessageProcessor.NeedToReadLongLength(buffer)) if (MessageProcessor.NeedToReadLongLength(buffer))
header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.LongLength); header.offset = ReadHelper.Read(stream, buffer, header.offset, Constants.LongLength);
Log.DumpBuffer($"[SimpleWebTransport] Raw Header", buffer, 0, header.offset); Log.DumpBuffer($"[SWT-ReceiveLoop]: Raw Header", buffer, 0, header.offset);
MessageProcessor.ValidateHeader(buffer, maxMessageSize, expectMask, opCodeContinuation); MessageProcessor.ValidateHeader(buffer, maxMessageSize, expectMask, opCodeContinuation);
@ -194,7 +194,7 @@ static Header ReadHeader(Config config, byte[] buffer, bool opCodeContinuation =
header.payloadLength = MessageProcessor.GetPayloadLength(buffer); header.payloadLength = MessageProcessor.GetPayloadLength(buffer);
header.finished = MessageProcessor.Finished(buffer); header.finished = MessageProcessor.Finished(buffer);
Log.Verbose($"[SimpleWebTransport] Header ln:{header.payloadLength} op:{header.opcode} mask:{expectMask}"); Log.Flood($"[SWT-ReceiveLoop]: Header ln:{header.payloadLength} op:{header.opcode} mask:{expectMask}");
return header; return header;
} }
@ -206,7 +206,7 @@ static void HandleArrayMessage(Config config, byte[] buffer, int msgOffset, int
ArrayBuffer arrayBuffer = CopyMessageToBuffer(bufferPool, expectMask, buffer, msgOffset, payloadLength); ArrayBuffer arrayBuffer = CopyMessageToBuffer(bufferPool, expectMask, buffer, msgOffset, payloadLength);
// dump after mask off // dump after mask off
Log.DumpBuffer($"[SimpleWebTransport] Message", arrayBuffer); Log.DumpBuffer($"[SWT-ReceiveLoop]: Message", arrayBuffer);
queue.Enqueue(new Message(conn.connId, arrayBuffer)); queue.Enqueue(new Message(conn.connId, arrayBuffer));
} }
@ -238,8 +238,8 @@ static void HandleCloseMessage(Config config, byte[] buffer, int msgOffset, int
} }
// dump after mask off // dump after mask off
Log.DumpBuffer($"[SimpleWebTransport] Message", buffer, msgOffset, payloadLength); Log.DumpBuffer($"[SWT-ReceiveLoop]: Message", buffer, msgOffset, payloadLength);
Log.Info($"[SimpleWebTransport] Close: {GetCloseCode(buffer, msgOffset)} message:{GetCloseMessage(buffer, msgOffset, payloadLength)}"); Log.Verbose($"[SWT-ReceiveLoop]: Close: {GetCloseCode(buffer, msgOffset)} message:{GetCloseMessage(buffer, msgOffset, payloadLength)}");
conn.Dispose(); conn.Dispose();
} }

View File

@ -71,7 +71,7 @@ public static void Loop(Config config)
// check if connected before sending message // check if connected before sending message
if (!client.Connected) if (!client.Connected)
{ {
Log.Info($"[SimpleWebTransport] SendLoop {conn} not connected"); Log.Verbose($"[SWT-SendLoop]: SendLoop {conn} not connected");
msg.Release(); msg.Release();
return; return;
} }
@ -101,7 +101,7 @@ public static void Loop(Config config)
// check if connected before sending message // check if connected before sending message
if (!client.Connected) if (!client.Connected)
{ {
Log.Info($"[SimpleWebTransport] SendLoop {conn} not connected"); Log.Verbose($"[SWT-SendLoop]: SendLoop {conn} not connected");
msg.Release(); msg.Release();
return; return;
} }
@ -113,7 +113,7 @@ public static void Loop(Config config)
} }
} }
Log.Info($"[SimpleWebTransport] {conn} Not Connected"); Log.Verbose($"[SWT-SendLoop]: {conn} Not Connected");
} }
catch (ThreadInterruptedException e) { Log.InfoException(e); } catch (ThreadInterruptedException e) { Log.InfoException(e); }
catch (ThreadAbortException e) { Log.InfoException(e); } catch (ThreadAbortException e) { Log.InfoException(e); }
@ -144,7 +144,7 @@ static int SendMessage(byte[] buffer, int startOffset, ArrayBuffer msg, bool set
offset += msgLength; offset += msgLength;
// dump before mask on // dump before mask on
Log.DumpBuffer("[SimpleWebTransport] Send", buffer, startOffset, offset); Log.DumpBuffer("[SWT-SendLoop]: Send", buffer, startOffset, offset);
if (setMask) if (setMask)
{ {

View File

@ -50,7 +50,7 @@ public bool TryHandshake(Connection conn)
if (!IsGet(getHeader.array)) if (!IsGet(getHeader.array))
{ {
Log.Warn($"[SimpleWebTransport] First bytes from client was not 'GET' for handshake, instead was {Log.BufferToString(getHeader.array, 0, GetSize)}", false); Log.Warn($"[SWT-ServerHandshake]: First bytes from client was not 'GET' for handshake, instead was {Log.BufferToString(getHeader.array, 0, GetSize)}");
return false; return false;
} }
} }
@ -66,6 +66,7 @@ public bool TryHandshake(Connection conn)
conn.request = new Request(msg); conn.request = new Request(msg);
conn.remoteAddress = conn.CalculateAddress(); conn.remoteAddress = conn.CalculateAddress();
Log.Info($"[SWT-ServerHandshake]: A client connected from {conn}");
return true; return true;
} }
@ -89,7 +90,7 @@ string ReadToEndForHandshake(Stream stream)
string msg = Encoding.ASCII.GetString(readBuffer.array, 0, readCount); string msg = Encoding.ASCII.GetString(readBuffer.array, 0, readCount);
// GET isn't in the bytes we read here, so we need to add it back // GET isn't in the bytes we read here, so we need to add it back
msg = $"GET{msg}"; msg = $"GET{msg}";
Log.Info($"Client Handshake Message:\r\n{msg}", false); Log.Verbose($"[SWT-ServerHandshake]: Client Handshake Message:\r\n{msg}");
return msg; return msg;
} }
@ -121,7 +122,7 @@ static void GetKey(string msg, byte[] keyBuffer)
{ {
int start = msg.IndexOf(KeyHeaderString, StringComparison.InvariantCultureIgnoreCase) + KeyHeaderString.Length; int start = msg.IndexOf(KeyHeaderString, StringComparison.InvariantCultureIgnoreCase) + KeyHeaderString.Length;
Log.Verbose($"[SimpleWebTransport] Handshake Key: {msg.Substring(start, KeyLength)}", false); Log.Verbose($"[SWT-ServerHandshake]: Handshake Key: {msg.Substring(start, KeyLength)}");
Encoding.ASCII.GetBytes(msg, start, KeyLength, keyBuffer, 0); Encoding.ASCII.GetBytes(msg, start, KeyLength, keyBuffer, 0);
} }
@ -132,7 +133,7 @@ static void AppendGuid(byte[] keyBuffer)
byte[] CreateHash(byte[] keyBuffer) byte[] CreateHash(byte[] keyBuffer)
{ {
Log.Verbose($"[SimpleWebTransport] Handshake Hashing {Encoding.ASCII.GetString(keyBuffer, 0, MergedKeyLength)}", false); Log.Verbose($"[SWT-ServerHandshake]: Handshake Hashing {Encoding.ASCII.GetString(keyBuffer, 0, MergedKeyLength)}");
return sha1.ComputeHash(keyBuffer, 0, MergedKeyLength); return sha1.ComputeHash(keyBuffer, 0, MergedKeyLength);
} }
@ -148,7 +149,7 @@ static void CreateResponse(byte[] keyHash, byte[] responseBuffer)
"Sec-WebSocket-Accept: {0}\r\n\r\n", "Sec-WebSocket-Accept: {0}\r\n\r\n",
keyHashString); keyHashString);
Log.Verbose($"[SimpleWebTransport] Handshake Response length {message.Length}, IsExpected {message.Length == ResponseLength}", false); Log.Verbose($"[SWT-ServerHandshake]: Handshake Response length {message.Length}, IsExpected {message.Length == ResponseLength}");
Encoding.ASCII.GetBytes(message, 0, ResponseLength, responseBuffer, 0); Encoding.ASCII.GetBytes(message, 0, ResponseLength, responseBuffer, 0);
} }
} }

View File

@ -35,10 +35,7 @@ public ServerSslHelper(SslConfig sslConfig)
if (config.enabled) if (config.enabled)
{ {
certificate = new X509Certificate2(config.certPath, config.certPassword); certificate = new X509Certificate2(config.certPath, config.certPassword);
Log.Info($"[SWT-ServerSslHelper]: SSL Certificate {certificate.Subject} loaded with expiration of {certificate.GetExpirationDateString()}");
Console.ForegroundColor = ConsoleColor.Cyan;
Console.WriteLine($"[SimpleWebTransport] SSL Certificate {certificate.Subject} loaded with expiration of {certificate.GetExpirationDateString()}");
Console.ResetColor();
} }
} }
@ -54,10 +51,7 @@ internal bool TryCreateStream(Connection conn)
} }
catch (Exception e) catch (Exception e)
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Error($"[SWT-ServerSslHelper]: Create SSLStream Failed: {e.Message}");
Console.WriteLine($"[SimpleWebTransport] Create SSLStream Failed: {e.Message}");
Console.ResetColor();
return false; return false;
} }
} }

View File

@ -108,9 +108,7 @@ public void ProcessMessageQueue(MonoBehaviour behaviour)
if (server.receiveQueue.Count > 0) if (server.receiveQueue.Count > 0)
{ {
Console.ForegroundColor = ConsoleColor.Yellow; Log.Warn($"[SWT-SimpleWebServer]: ProcessMessageQueue has {server.receiveQueue.Count} remaining.");
Console.WriteLine($"SimpleWebServer ProcessMessageQueue has {server.receiveQueue.Count} remaining.");
Console.ResetColor();
} }
} }
} }

View File

@ -37,9 +37,7 @@ public void Listen(int port)
listener = TcpListener.Create(port); listener = TcpListener.Create(port);
listener.Start(); listener.Start();
Console.ForegroundColor = ConsoleColor.Green; Log.Info($"[SWT-WebSocketServer]: Server Started on {port}!", ConsoleColor.Green);
Console.WriteLine($"[SimpleWebTransport] Server Started on {port}!");
Console.ResetColor();
acceptThread = new Thread(acceptLoop); acceptThread = new Thread(acceptLoop);
acceptThread.IsBackground = true; acceptThread.IsBackground = true;
@ -55,7 +53,7 @@ public void Stop()
listener?.Stop(); listener?.Stop();
acceptThread = null; acceptThread = null;
Console.WriteLine($"[SimpleWebTransport] Server stopped...closing all connections."); Log.Info($"[SWT-WebSocketServer]: Server stopped...closing all connections.");
// make copy so that foreach doesn't break if values are removed // make copy so that foreach doesn't break if values are removed
Connection[] connectionsCopy = connections.Values.ToArray(); Connection[] connectionsCopy = connections.Values.ToArray();
@ -80,7 +78,7 @@ void acceptLoop()
// this might not be a problem as HandshakeAndReceiveLoop checks for stop // this might not be a problem as HandshakeAndReceiveLoop checks for stop
// and returns/disposes before sending message to queue // and returns/disposes before sending message to queue
Connection conn = new Connection(client, AfterConnectionDisposed); Connection conn = new Connection(client, AfterConnectionDisposed);
Console.WriteLine($"[SimpleWebTransport] A client connected {conn}", false); Log.Verbose($"[SWT-WebSocketServer]: A client connected from {conn}");
// handshake needs its own thread as it needs to wait for message from client // handshake needs its own thread as it needs to wait for message from client
Thread receiveThread = new Thread(() => HandshakeAndReceiveLoop(conn)); Thread receiveThread = new Thread(() => HandshakeAndReceiveLoop(conn));
@ -110,9 +108,7 @@ void HandshakeAndReceiveLoop(Connection conn)
bool success = sslHelper.TryCreateStream(conn); bool success = sslHelper.TryCreateStream(conn);
if (!success) if (!success)
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Warn($"[SWT-WebSocketServer]: Failed to create SSL Stream {conn}");
Console.WriteLine($"[SimpleWebTransport] Failed to create SSL Stream {conn}");
Console.ResetColor();
conn.Dispose(); conn.Dispose();
return; return;
} }
@ -120,12 +116,10 @@ void HandshakeAndReceiveLoop(Connection conn)
success = handShake.TryHandshake(conn); success = handShake.TryHandshake(conn);
if (success) if (success)
Console.WriteLine($"[SimpleWebTransport] Sent Handshake {conn}, false"); Log.Verbose($"[SWT-WebSocketServer]: Sent Handshake {conn}, false");
else else
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Warn($"[SWT-WebSocketServer]: Handshake Failed {conn}");
Console.WriteLine($"[SimpleWebTransport] Handshake Failed {conn}");
Console.ResetColor();
conn.Dispose(); conn.Dispose();
return; return;
} }
@ -133,7 +127,7 @@ void HandshakeAndReceiveLoop(Connection conn)
// check if Stop has been called since accepting this client // check if Stop has been called since accepting this client
if (serverStopped) if (serverStopped)
{ {
Console.WriteLine("[SimpleWebTransport] Server stops after successful handshake", false); Log.Warn("[SWT-WebSocketServer]: Server stopped after successful handshake");
return; return;
} }
@ -168,21 +162,15 @@ void HandshakeAndReceiveLoop(Connection conn)
} }
catch (ThreadInterruptedException e) catch (ThreadInterruptedException e)
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Error($"[SWT-WebSocketServer]: Handshake ThreadInterruptedException {e.Message}");
Console.WriteLine($"[SimpleWebTransport] Handshake ThreadInterruptedException {e.Message}");
Console.ResetColor();
} }
catch (ThreadAbortException e) catch (ThreadAbortException e)
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Error($"[SWT-WebSocketServer]: Handshake ThreadAbortException {e.Message}");
Console.WriteLine($"[SimpleWebTransport] Handshake ThreadAbortException {e.Message}");
Console.ResetColor();
} }
catch (Exception e) catch (Exception e)
{ {
Console.ForegroundColor = ConsoleColor.Red; Log.Error($"[SWT-WebSocketServer]: Handshake Exception {e.Message}");
Console.WriteLine($"[SimpleWebTransport] Handshake Exception {e.Message}");
Console.ResetColor();
} }
finally finally
{ {
@ -208,29 +196,20 @@ public void Send(int id, ArrayBuffer buffer)
conn.sendPending.Set(); conn.sendPending.Set();
} }
else else
{ Log.Warn($"[SWT-WebSocketServer]: Cannot send message to {id} because connection was not found in dictionary. Maybe it disconnected.");
Console.ForegroundColor = ConsoleColor.Yellow;
Console.WriteLine($"[SimpleWebTransport] Cannot send message to {id} because connection was not found in dictionary. Maybe it disconnected.");
Console.ResetColor();
}
} }
public bool CloseConnection(int id) public bool CloseConnection(int id)
{ {
if (connections.TryGetValue(id, out Connection conn)) if (connections.TryGetValue(id, out Connection conn))
{ {
Console.ForegroundColor = ConsoleColor.Magenta; Log.Info($"[SWT-WebSocketServer]: Disconnecting connection {id}");
Console.WriteLine($"[SimpleWebTransport] Kicking connection {id}");
Console.ResetColor();
conn.Dispose(); conn.Dispose();
return true; return true;
} }
else else
{ {
Console.ForegroundColor = ConsoleColor.Yellow; Log.Warn($"[SWT-WebSocketServer]: Failed to kick {id} because id not found.");
Console.WriteLine($"[SimpleWebTransport] Failed to kick {id} because id not found.");
Console.ResetColor();
return false; return false;
} }
} }
@ -239,9 +218,7 @@ public string GetClientAddress(int id)
{ {
if (!connections.TryGetValue(id, out Connection conn)) if (!connections.TryGetValue(id, out Connection conn))
{ {
Console.ForegroundColor = ConsoleColor.Yellow; Log.Warn($"[SWT-WebSocketServer]: Cannot get address of connection {id} because connection was not found in dictionary.");
Console.WriteLine($"[SimpleWebTransport] Cannot get address of connection {id} because connection was not found in dictionary.");
Console.ResetColor();
return null; return null;
} }
@ -252,9 +229,7 @@ public Request GetClientRequest(int id)
{ {
if (!connections.TryGetValue(id, out Connection conn)) if (!connections.TryGetValue(id, out Connection conn))
{ {
Console.ForegroundColor = ConsoleColor.Yellow; Log.Warn($"[SWT-WebSocketServer]: Cannot get request of connection {id} because connection was not found in dictionary.");
Console.WriteLine($"[SimpleWebTransport] Cannot get request of connection {id} because connection was not found in dictionary.");
Console.ResetColor();
return null; return null;
} }

View File

@ -156,7 +156,7 @@ public override void ClientConnect(Uri uri)
// connecting or connected // connecting or connected
if (ClientConnected()) if (ClientConnected())
{ {
Log.Warn("[SimpleWebTransport] Already Connected"); Log.Warn("[SWT-ClientConnect]: Already Connected");
return; return;
} }
@ -195,19 +195,19 @@ public override void ClientSend(ArraySegment<byte> segment, int channelId)
{ {
if (!ClientConnected()) if (!ClientConnected())
{ {
Log.Error("[SimpleWebTransport] Not Connected"); Log.Error("[SWT-ClientSend]: Not Connected");
return; return;
} }
if (segment.Count > maxMessageSize) if (segment.Count > maxMessageSize)
{ {
Log.Error("[SimpleWebTransport] Message greater than max size"); Log.Error("[SWT-ClientSend]: Message greater than max size");
return; return;
} }
if (segment.Count == 0) if (segment.Count == 0)
{ {
Log.Error("[SimpleWebTransport] Message count was zero"); Log.Error("[SWT-ClientSend]: Message count was zero");
return; return;
} }
@ -248,7 +248,7 @@ public override bool ServerActive()
public override void ServerStart() public override void ServerStart()
{ {
if (ServerActive()) if (ServerActive())
Log.Warn("[SimpleWebTransport] Server Already Started"); Log.Warn("[SWT-ServerStart]: Server Already Started");
SslConfig config = SslConfigLoader.Load(sslEnabled, sslCertJson, sslProtocols); SslConfig config = SslConfigLoader.Load(sslEnabled, sslCertJson, sslProtocols);
server = new SimpleWebServer(serverMaxMsgsPerTick, TcpConfig, maxMessageSize, maxHandshakeSize, config); server = new SimpleWebServer(serverMaxMsgsPerTick, TcpConfig, maxMessageSize, maxHandshakeSize, config);
@ -283,19 +283,19 @@ public override void ServerSend(int connectionId, ArraySegment<byte> segment, in
{ {
if (!ServerActive()) if (!ServerActive())
{ {
Log.Error("[SimpleWebTransport] Server Not Active", false); Log.Error("[SWT-ServerSend]: Server Not Active");
return; return;
} }
if (segment.Count > maxMessageSize) if (segment.Count > maxMessageSize)
{ {
Log.Error("[SimpleWebTransport] Message greater than max size", false); Log.Error("[SWT-ServerSend]: Message greater than max size");
return; return;
} }
if (segment.Count == 0) if (segment.Count == 0)
{ {
Log.Error("[SimpleWebTransport] Message count was zero", false); Log.Error("[SWT-ServerSend]: Message count was zero");
return; return;
} }