fix(SWT): Reduced allocations in logging

This commit is contained in:
MrGadget 2024-09-20 04:35:30 -04:00
parent af97b197af
commit 7fa4d312ae
14 changed files with 43 additions and 58 deletions

View File

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

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($"[SWT-ClientHandshake]: Handshake Hashing {0}", Encoding.ASCII.GetString(keySumBytes)); Log.Verbose("[SWT-ClientHandshake]: Handshake Hashing {0}", 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
@ -55,14 +55,14 @@ public bool TryHandshake(Connection conn, Uri uri)
} }
string responseString = Encoding.ASCII.GetString(responseBuffer, 0, lengthOrNull.Value); string responseString = Encoding.ASCII.GetString(responseBuffer, 0, lengthOrNull.Value);
Log.Verbose($"[SWT-ClientHandshake]: Handshake Response {0}", responseString); Log.Verbose("[SWT-ClientHandshake]: Handshake Response {0}", 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($"[SWT-ClientHandshake]: Unexpected Handshake Response {0}", responseString); Log.Error("[SWT-ClientHandshake]: Unexpected Handshake Response {0}", responseString);
return false; return false;
} }
@ -72,10 +72,7 @@ public bool TryHandshake(Connection conn, Uri uri)
if (responseKey != expectedResponse) if (responseKey != expectedResponse)
{ {
Log.Error($"[SWT-ClientHandshake]: Response key incorrect\n" + Log.Error("[SWT-ClientHandshake]: Response key incorrect\nExpected:{0}\nResponse:{1}\nThis can happen if Websocket Protocol is not installed in Windows Server Roles.", expectedResponse, responseKey);
$"Expected:{0}\n" +
$"Response:{1}\n" +
$"This can happen if Websocket Protocol is not installed in Windows Server Roles.", expectedResponse, responseKey);
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($"[SWT-ClientSslHelper]: Create SSLStream Failed: {0}\n{1}\n\n", e.Message, e.StackTrace); Log.Error("[SWT-ClientSslHelper]: Create SSLStream Failed: {0}\n{1}\n\n", e.Message, e.StackTrace);
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($"[SWT-WebSocketClientStandAlone]: Failed to create Stream with {0}", serverAddress); Log.Warn("[SWT-WebSocketClientStandAlone]: Failed to create Stream with {0}", 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($"[SWT-WebSocketClientStandAlone]: Failed Handshake with {0}", serverAddress); Log.Warn("[SWT-WebSocketClientStandAlone]: Failed Handshake with {0}", serverAddress);
conn.Dispose(); conn.Dispose();
return; return;
} }
Log.Info($"[SWT-WebSocketClientStandAlone]: HandShake Successful with {0}", serverAddress); Log.Info("[SWT-WebSocketClientStandAlone]: HandShake Successful with {0}", serverAddress);
state = ClientState.Connected; state = ClientState.Connected;

View File

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

View File

@ -226,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($"[SWT-BufferPool]: BufferPool Failed to create bucket for smallest. bucket:{0} smallest:{1}", buckets[0].arraySize, smallest); Log.Error("[SWT-BufferPool]: BufferPool Failed to create bucket for smallest. bucket:{0} smallest:{1}", buckets[0].arraySize, 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($"[SWT-BufferPool]: BufferPool Failed to create bucket for largest. bucket:{0} smallest:{1}", largestBucket, largest); Log.Error("[SWT-BufferPool]: BufferPool Failed to create bucket for largest. bucket:{0} smallest:{1}", largestBucket, 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($"[SWT-Connection]: Dispose {0}", ToString()); Log.Verbose("[SWT-Connection]: Dispose {0}", ToString());
// check hasDisposed first to stop ThreadInterruptedException on lock // check hasDisposed first to stop ThreadInterruptedException on lock
if (hasDisposed) return; if (hasDisposed) return;
Log.Verbose($"[SWT-Connection]: Connection Close: {0}", ToString()); Log.Verbose("[SWT-Connection]: Connection Close: {0}", ToString());
lock (disposedLock) lock (disposedLock)
{ {

View File

@ -221,18 +221,6 @@ public static void Warn<T>(string msg, T arg1)
Warn($"{msg} {arg1}"); Warn($"{msg} {arg1}");
} }
//public static void Warn<T1, T2>(string msg, T1 arg1, T2 arg2)
//{
// if (minLogLevel > Levels.Warn) return;
// Warn($"{msg} {arg1} {arg2}");
//}
//public static void Warn<T1, T2, T3>(string msg, T1 arg1, T2 arg2, T3 arg3)
//{
// if (minLogLevel > Levels.Warn) return;
// Warn($"{msg} {arg1} {arg2} {arg3}");
//}
/// <summary> /// <summary>
/// Logs info to console if minLogLevel is set to Error or lower /// Logs info to console if minLogLevel is set to Error or lower
/// </summary> /// </summary>

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.Verbose($"[SWT-ReceiveLoop]: {0} Not Connected", conn); Log.Verbose("[SWT-ReceiveLoop]: {0} Not Connected", conn);
} }
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($"[SWT-ReceiveLoop]: ReceiveLoop SocketException\n{0}", e.Message); Log.Warn("[SWT-ReceiveLoop]: ReceiveLoop SocketException\n{0}", 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($"[SWT-ReceiveLoop]: ReceiveLoop IOException\n{0}", e.Message); Log.Warn("[SWT-ReceiveLoop]: ReceiveLoop IOException\n{0}", e.Message);
queue.Enqueue(new Message(conn.connId, e)); queue.Enqueue(new Message(conn.connId, e));
} }
catch (InvalidDataException e) catch (InvalidDataException e)
{ {
Log.Error($"[SWT-ReceiveLoop]: Invalid data from {0}\n{1}\n{2}\n\n", conn, e.Message, e.StackTrace); Log.Error("[SWT-ReceiveLoop]: Invalid data from {0}\n{1}\n{2}\n\n", conn, e.Message, e.StackTrace);
queue.Enqueue(new Message(conn.connId, e)); queue.Enqueue(new Message(conn.connId, e));
} }
catch (Exception e) catch (Exception e)
@ -239,7 +239,7 @@ static void HandleCloseMessage(Config config, byte[] buffer, int msgOffset, int
// dump after mask off // dump after mask off
Log.DumpBuffer($"[SWT-ReceiveLoop]: Message", buffer, msgOffset, payloadLength); Log.DumpBuffer($"[SWT-ReceiveLoop]: Message", buffer, msgOffset, payloadLength);
Log.Verbose($"[SWT-ReceiveLoop]: Close: {0} message:{1}", GetCloseCode(buffer, msgOffset), GetCloseMessage(buffer, msgOffset, payloadLength)); Log.Verbose("[SWT-ReceiveLoop]: Close: {0} message:{1}", GetCloseCode(buffer, msgOffset), 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.Verbose($"[SWT-SendLoop]: SendLoop {0} not connected", conn); Log.Verbose("[SWT-SendLoop]: SendLoop {0} not connected", conn);
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.Verbose($"[SWT-SendLoop]: SendLoop {0} not connected", conn); Log.Verbose("[SWT-SendLoop]: SendLoop {0} not connected", conn);
msg.Release(); msg.Release();
return; return;
} }
@ -113,7 +113,7 @@ public static void Loop(Config config)
} }
} }
Log.Verbose($"[SWT-SendLoop]: {0} Not Connected", conn); Log.Verbose("[SWT-SendLoop]: {0} Not Connected", conn);
} }
catch (ThreadInterruptedException e) { Log.InfoException(e); } catch (ThreadInterruptedException e) { Log.InfoException(e); }
catch (ThreadAbortException e) { Log.InfoException(e); } catch (ThreadAbortException e) { Log.InfoException(e); }

View File

@ -50,7 +50,7 @@ public bool TryHandshake(Connection conn)
if (!IsGet(getHeader.array)) if (!IsGet(getHeader.array))
{ {
Log.Warn($"[SWT-ServerHandshake]: First bytes from client was not 'GET' for handshake, instead was {0}", Log.BufferToString(getHeader.array, 0, GetSize)); Log.Warn("[SWT-ServerHandshake]: First bytes from client was not 'GET' for handshake, instead was {0}", Log.BufferToString(getHeader.array, 0, GetSize));
return false; return false;
} }
} }
@ -90,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.Verbose($"[SWT-ServerHandshake]: Client Handshake Message:\r\n{0}", msg); Log.Verbose("[SWT-ServerHandshake]: Client Handshake Message:\r\n{0}", msg);
return msg; return msg;
} }
@ -122,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($"[SWT-ServerHandshake]: Handshake Key: {0}", msg.Substring(start, KeyLength)); Log.Verbose("[SWT-ServerHandshake]: Handshake Key: {0}", msg.Substring(start, KeyLength));
Encoding.ASCII.GetBytes(msg, start, KeyLength, keyBuffer, 0); Encoding.ASCII.GetBytes(msg, start, KeyLength, keyBuffer, 0);
} }
@ -133,7 +133,7 @@ static void AppendGuid(byte[] keyBuffer)
byte[] CreateHash(byte[] keyBuffer) byte[] CreateHash(byte[] keyBuffer)
{ {
Log.Verbose($"[SWT-ServerHandshake]: Handshake Hashing {0}", Encoding.ASCII.GetString(keyBuffer, 0, MergedKeyLength)); Log.Verbose("[SWT-ServerHandshake]: Handshake Hashing {0}", Encoding.ASCII.GetString(keyBuffer, 0, MergedKeyLength));
return sha1.ComputeHash(keyBuffer, 0, MergedKeyLength); return sha1.ComputeHash(keyBuffer, 0, MergedKeyLength);
} }
@ -149,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($"[SWT-ServerHandshake]: Handshake Response length {0}, IsExpected {1}", message.Length, message.Length == ResponseLength); Log.Verbose("[SWT-ServerHandshake]: Handshake Response length {0}, IsExpected {1}", message.Length, message.Length == ResponseLength);
Encoding.ASCII.GetBytes(message, 0, ResponseLength, responseBuffer, 0); Encoding.ASCII.GetBytes(message, 0, ResponseLength, responseBuffer, 0);
} }
} }

View File

@ -49,7 +49,7 @@ internal bool TryCreateStream(Connection conn)
} }
catch (Exception e) catch (Exception e)
{ {
Log.Error($"[SWT-ServerSslHelper]: Create SSLStream Failed: {0}", e.Message); Log.Error("[SWT-ServerSslHelper]: Create SSLStream Failed: {0}", e.Message);
return false; return false;
} }
} }

View File

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

View File

@ -37,7 +37,7 @@ public void Listen(int port)
listener = TcpListener.Create(port); listener = TcpListener.Create(port);
listener.Start(); listener.Start();
Log.Verbose($"[SWT-WebSocketServer]: Server Started on {0}", port); Log.Verbose("[SWT-WebSocketServer]: Server Started on {0}", port);
acceptThread = new Thread(acceptLoop); acceptThread = new Thread(acceptLoop);
acceptThread.IsBackground = true; acceptThread.IsBackground = true;
@ -53,7 +53,7 @@ public void Stop()
listener?.Stop(); listener?.Stop();
acceptThread = null; acceptThread = null;
Log.Verbose($"[SWT-WebSocketServer]: Server stopped...closing all connections."); Log.Verbose("[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();
@ -78,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);
Log.Verbose($"[SWT-WebSocketServer]: A client connected from {0}", conn); Log.Verbose("[SWT-WebSocketServer]: A client connected from {0}", 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));
@ -108,7 +108,7 @@ void HandshakeAndReceiveLoop(Connection conn)
bool success = sslHelper.TryCreateStream(conn); bool success = sslHelper.TryCreateStream(conn);
if (!success) if (!success)
{ {
Log.Warn($"[SWT-WebSocketServer]: Failed to create SSL Stream {0}", conn); Log.Warn("[SWT-WebSocketServer]: Failed to create SSL Stream {0}", conn);
conn.Dispose(); conn.Dispose();
return; return;
} }
@ -116,10 +116,10 @@ void HandshakeAndReceiveLoop(Connection conn)
success = handShake.TryHandshake(conn); success = handShake.TryHandshake(conn);
if (success) if (success)
Log.Verbose($"[SWT-WebSocketServer]: Sent Handshake {0}, false", conn); Log.Verbose("[SWT-WebSocketServer]: Sent Handshake {0}, false", conn);
else else
{ {
Log.Warn($"[SWT-WebSocketServer]: Handshake Failed {0}", conn); Log.Warn("[SWT-WebSocketServer]: Handshake Failed {0}", conn);
conn.Dispose(); conn.Dispose();
return; return;
} }
@ -162,15 +162,15 @@ void HandshakeAndReceiveLoop(Connection conn)
} }
catch (ThreadInterruptedException e) catch (ThreadInterruptedException e)
{ {
Log.Error($"[SWT-WebSocketServer]: Handshake ThreadInterruptedException {0}", e.Message); Log.Error("[SWT-WebSocketServer]: Handshake ThreadInterruptedException {0}", e.Message);
} }
catch (ThreadAbortException e) catch (ThreadAbortException e)
{ {
Log.Error($"[SWT-WebSocketServer]: Handshake ThreadAbortException {0}", e.Message); Log.Error("[SWT-WebSocketServer]: Handshake ThreadAbortException {0}", e.Message);
} }
catch (Exception e) catch (Exception e)
{ {
Log.Error($"[SWT-WebSocketServer]: Handshake Exception {0}", e.Message); Log.Error("[SWT-WebSocketServer]: Handshake Exception {0}", e.Message);
} }
finally finally
{ {
@ -196,7 +196,7 @@ public void Send(int id, ArrayBuffer buffer)
conn.sendPending.Set(); conn.sendPending.Set();
} }
else else
Log.Warn($"[SWT-WebSocketServer]: Cannot send message to {0} because connection was not found in dictionary. Maybe it disconnected.", id); Log.Warn("[SWT-WebSocketServer]: Cannot send message to {0} because connection was not found in dictionary. Maybe it disconnected.", id);
} }
public bool CloseConnection(int id) public bool CloseConnection(int id)
@ -209,7 +209,7 @@ public bool CloseConnection(int id)
} }
else else
{ {
Log.Warn($"[SWT-WebSocketServer]: Failed to kick {0} because id not found.", id); Log.Warn("[SWT-WebSocketServer]: Failed to kick {0} because id not found.", id);
return false; return false;
} }
} }
@ -218,7 +218,7 @@ public string GetClientAddress(int id)
{ {
if (!connections.TryGetValue(id, out Connection conn)) if (!connections.TryGetValue(id, out Connection conn))
{ {
Log.Warn($"[SWT-WebSocketServer]: Cannot get address of connection {0} because connection was not found in dictionary.", id); Log.Warn("[SWT-WebSocketServer]: Cannot get address of connection {0} because connection was not found in dictionary.", id);
return null; return null;
} }
@ -229,7 +229,7 @@ public Request GetClientRequest(int id)
{ {
if (!connections.TryGetValue(id, out Connection conn)) if (!connections.TryGetValue(id, out Connection conn))
{ {
Log.Warn($"[SWT-WebSocketServer]: Cannot get request of connection {0} because connection was not found in dictionary.", id); Log.Warn("[SWT-WebSocketServer]: Cannot get request of connection {0} because connection was not found in dictionary.", id);
return null; return null;
} }