Skip to content

Commit bc643a1

Browse files
committed
Warning/error logs don't allocate if disabled.
This should completely eliminate all performance overhead from the logging when it's disabled. This proves relevant during DDoS attacks, as the logging is actually a serious amplifier for even low-bandwidth UDP spam. This is done by moving it to an interpolated string handler, so we can skip running string formatting and such when the log channel is disabled.
1 parent 32820c3 commit bc643a1

10 files changed

+139
-58
lines changed

Lidgren.Network/NetConnection.Handshake.cs

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -89,7 +89,7 @@ internal void UnconnectedHeartbeat(double now)
8989
case NetConnectionStatus.None:
9090
case NetConnectionStatus.ReceivedInitiation:
9191
default:
92-
m_peer.LogWarning("Time to resend handshake, but status is " + m_status);
92+
m_peer.LogWarning($"Time to resend handshake, but status is {m_status}");
9393
break;
9494
}
9595
}
@@ -231,7 +231,8 @@ public void Approve()
231231
{
232232
if (m_status != NetConnectionStatus.RespondedAwaitingApproval)
233233
{
234-
m_peer.LogWarning("Approve() called in wrong status; expected RespondedAwaitingApproval; got " + m_status);
234+
m_peer.LogWarning(
235+
$"Approve() called in wrong status; expected RespondedAwaitingApproval; got {m_status}");
235236
return;
236237
}
237238

@@ -248,7 +249,8 @@ public void Approve(NetOutgoingMessage localHail)
248249
{
249250
if (m_status != NetConnectionStatus.RespondedAwaitingApproval)
250251
{
251-
m_peer.LogWarning("Approve() called in wrong status; expected RespondedAwaitingApproval; got " + m_status);
252+
m_peer.LogWarning(
253+
$"Approve() called in wrong status; expected RespondedAwaitingApproval; got {m_status}");
252254
return;
253255
}
254256

@@ -468,7 +470,7 @@ private bool ValidateHandshakeData(int ptr, int payloadLength, out byte[]? hail)
468470
{
469471
// whatever; we failed
470472
ExecuteDisconnect("Handshake data validation failed", true);
471-
m_peer.LogWarning("ReadRemoteHandshakeData failed: " + ex.Message);
473+
m_peer.LogWarning($"ReadRemoteHandshakeData failed: {ex.Message}");
472474
return false;
473475
}
474476
return true;

Lidgren.Network/NetConnection.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -476,7 +476,7 @@ internal void ReceivedLibraryMessage(NetMessageType tp, int ptr, int payloadLeng
476476
m_peer.HandleNatIntroduction(ptr);
477477
break;
478478
default:
479-
m_peer.LogWarning("Connection received unhandled library message: " + tp);
479+
m_peer.LogWarning($"Connection received unhandled library message: {tp}");
480480
break;
481481
}
482482
}

Lidgren.Network/NetPeer.Internal.cs

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -104,7 +104,7 @@ internal void ReleaseMessage(NetIncomingMessage msg)
104104
}
105105
catch (Exception ex)
106106
{
107-
LogWarning("Receive callback exception:" + ex);
107+
LogWarning($"Receive callback exception:{ex}");
108108
}
109109
}
110110
}
@@ -439,7 +439,7 @@ private void Heartbeat()
439439
return;
440440

441441
default:
442-
LogWarning("Socket exception: " + sx.ToString());
442+
LogWarning($"Socket exception: {sx}");
443443
return;
444444
}
445445
}
@@ -527,14 +527,14 @@ private void ReceiveSocketData(double now)
527527

528528
if (bytesReceived - ptr < payloadByteLength)
529529
{
530-
LogWarning("Malformed packet from " + (NetEndPoint)senderRemote + "; stated payload length " + payloadByteLength
531-
+ ", remaining bytes " + (bytesReceived - ptr));
530+
LogWarning(
531+
$"Malformed packet from {(NetEndPoint)senderRemote}; stated payload length {payloadByteLength}, remaining bytes {(bytesReceived - ptr)}");
532532
return;
533533
}
534534

535535
if (tp >= NetMessageType.Unused1 && tp <= NetMessageType.Unused29)
536536
{
537-
ThrowOrLog("Unexpected NetMessageType: " + tp);
537+
LogWarning($"Unexpected NetMessageType: {tp}");
538538
return;
539539
}
540540

@@ -587,7 +587,7 @@ private void ReceiveSocketData(double now)
587587
}
588588
catch (Exception ex)
589589
{
590-
LogError("Packet parsing error: " + ex.Message + " from " + (NetEndPoint)senderRemote);
590+
LogError($"Packet parsing error: {ex.Message} from {(NetEndPoint)senderRemote}");
591591
}
592592
ptr += payloadByteLength;
593593
}
@@ -725,7 +725,7 @@ private void ReceivedUnconnectedLibraryMessage(double now, NetEndPoint senderEnd
725725
}
726726
}
727727

728-
LogWarning("Received unhandled library message " + tp + " from " + senderEndPoint);
728+
LogWarning($"Received unhandled library message {tp} from {senderEndPoint}");
729729
return;
730730
case NetMessageType.Connect:
731731
if (m_configuration.AcceptIncomingConnections == false)
@@ -758,7 +758,7 @@ private void ReceivedUnconnectedLibraryMessage(double now, NetEndPoint senderEnd
758758
LogVerbose("Received Disconnect from unconnected source: " + senderEndPoint);
759759
return;
760760
default:
761-
LogWarning("Received unhandled library message " + tp + " from " + senderEndPoint);
761+
LogWarning($"Received unhandled library message {tp} from {senderEndPoint}");
762762
return;
763763
}
764764
}

Lidgren.Network/NetPeer.LatencySimulation.cs

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -183,7 +183,7 @@ internal bool ActuallySendPacket(byte[] data, int numBytes, NetEndPoint target,
183183

184184
int bytesSent = NetFastSocket.SendTo(m_socket, data, 0, numBytes, SocketFlags.None, realTarget);
185185
if (numBytes != bytesSent)
186-
LogWarning("Failed to send the full " + numBytes + "; only " + bytesSent + " bytes sent in packet!");
186+
LogWarning($"Failed to send the full {numBytes}; only {bytesSent} bytes sent in packet!");
187187

188188
// LogDebug("Sent " + numBytes + " bytes");
189189
}
@@ -201,11 +201,11 @@ internal bool ActuallySendPacket(byte[] data, int numBytes, NetEndPoint target,
201201
connectionReset = true;
202202
return false;
203203
}
204-
LogError("Failed to send packet: " + sx);
204+
LogError($"Failed to send packet: {sx}");
205205
}
206206
catch (Exception ex)
207207
{
208-
LogError("Failed to send packet: " + ex);
208+
LogError($"Failed to send packet: {ex}");
209209
}
210210
finally
211211
{
@@ -232,7 +232,7 @@ internal bool SendMTUPacket(int numBytes, NetEndPoint target)
232232

233233
int bytesSent = NetFastSocket.SendTo(m_socket, m_sendBuffer, 0, numBytes, SocketFlags.None, target);
234234
if (numBytes != bytesSent)
235-
LogWarning("Failed to send the full " + numBytes + "; only " + bytesSent + " bytes sent in packet!");
235+
LogWarning($"Failed to send the full {numBytes}; only {bytesSent} bytes sent in packet!");
236236

237237
m_statistics.PacketSent(numBytes, 1);
238238
}
@@ -248,11 +248,11 @@ internal bool SendMTUPacket(int numBytes, NetEndPoint target)
248248
}
249249
if (sx.SocketErrorCode == SocketError.ConnectionReset)
250250
return true;
251-
LogError("Failed to send packet: (" + sx.SocketErrorCode + ") " + sx);
251+
LogError($"Failed to send packet: ({sx.SocketErrorCode}) {sx}");
252252
}
253253
catch (Exception ex)
254254
{
255-
LogError("Failed to send packet: " + ex);
255+
LogError($"Failed to send packet: {ex}");
256256
}
257257
finally
258258
{

Lidgren.Network/NetPeer.Logging.cs

Lines changed: 109 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -19,53 +19,132 @@ USE OR OTHER DEALINGS IN THE SOFTWARE.
1919

2020
using System;
2121
using System.Diagnostics;
22+
using System.Runtime.CompilerServices;
2223

23-
namespace Lidgren.Network
24+
namespace Lidgren.Network;
25+
26+
public partial class NetPeer
2427
{
25-
public partial class NetPeer
26-
{
27-
internal event Action<NetIncomingMessageType, string>? LogEvent;
28+
internal event Action<NetIncomingMessageType, string>? LogEvent;
2829

29-
[Conditional("DEBUG")]
30-
internal void LogVerbose(string message)
31-
{
30+
[Conditional("DEBUG")]
31+
internal void LogVerbose(string message)
32+
{
3233
#if __ANDROID__
33-
Android.Util.Log.WriteLine(Android.Util.LogPriority.Verbose, "", message);
34+
Android.Util.Log.WriteLine(Android.Util.LogPriority.Verbose, "", message);
3435
#endif
35-
SendLogBase(NetIncomingMessageType.VerboseDebugMessage, message);
36-
}
36+
SendLogBase(NetIncomingMessageType.VerboseDebugMessage, message);
37+
}
3738

38-
[Conditional("DEBUG")]
39-
internal void LogDebug(string message)
40-
{
39+
[Conditional("DEBUG")]
40+
internal void LogDebug(string message)
41+
{
4142
#if __ANDROID__
42-
Android.Util.Log.WriteLine(Android.Util.LogPriority.Debug, "", message);
43+
Android.Util.Log.WriteLine(Android.Util.LogPriority.Debug, "", message);
4344
#endif
44-
SendLogBase(NetIncomingMessageType.DebugMessage, message);
45-
}
45+
SendLogBase(NetIncomingMessageType.DebugMessage, message);
46+
}
4647

47-
internal void LogWarning(string message)
48-
{
48+
internal void LogWarning(string message)
49+
{
4950
#if __ANDROID__
50-
Android.Util.Log.WriteLine(Android.Util.LogPriority.Warn, "", message);
51+
Android.Util.Log.WriteLine(Android.Util.LogPriority.Warn, "", message);
5152
#endif
52-
SendLogBase(NetIncomingMessageType.WarningMessage, message);
53-
}
53+
SendLogBase(NetIncomingMessageType.WarningMessage, message);
54+
}
5455

55-
internal void LogError(string message)
56-
{
56+
internal void LogError(string message)
57+
{
5758
#if __ANDROID__
58-
Android.Util.Log.WriteLine(Android.Util.LogPriority.Error, "", message);
59+
Android.Util.Log.WriteLine(Android.Util.LogPriority.Error, "", message);
5960
#endif
60-
SendLogBase(NetIncomingMessageType.ErrorMessage, message);
61+
SendLogBase(NetIncomingMessageType.ErrorMessage, message);
62+
}
63+
64+
private void SendLogBase(NetIncomingMessageType type, string text)
65+
{
66+
LogEvent?.Invoke(type, text);
67+
68+
if (m_configuration.IsMessageTypeEnabled(type))
69+
ReleaseMessage(CreateIncomingMessage(type, text));
70+
}
71+
72+
private bool CheckLogEnabled(NetIncomingMessageType type)
73+
{
74+
return m_configuration.IsMessageTypeEnabled(type) || LogEvent != null;
75+
}
76+
77+
#if NET6_0_OR_GREATER && !__ANDROID__
78+
// On supported TFMs, use an interpolated string handler,
79+
// so we can avoid running string formatting if a log level is disabled.
80+
internal void LogWarning([InterpolatedStringHandlerArgument("")] NetWarningLogInterpolatedStringHandler text)
81+
{
82+
SendLogBase(NetIncomingMessageType.WarningMessage, text.Implementation);
83+
}
84+
85+
internal void LogError([InterpolatedStringHandlerArgument("")] NetErrorLogInterpolatedStringHandler text)
86+
{
87+
SendLogBase(NetIncomingMessageType.ErrorMessage, text.Implementation);
88+
}
89+
90+
private void SendLogBase(NetIncomingMessageType type, DefaultInterpolatedStringHandler text)
91+
{
92+
if (!CheckLogEnabled(type))
93+
return;
94+
95+
SendLogBase(type, text.ToStringAndClear());
96+
}
97+
98+
[InterpolatedStringHandler]
99+
internal ref struct NetErrorLogInterpolatedStringHandler
100+
{
101+
public DefaultInterpolatedStringHandler Implementation;
102+
103+
public NetErrorLogInterpolatedStringHandler(
104+
int literalLength,
105+
int formattedCount,
106+
NetPeer peer,
107+
out bool handlerIsValid)
108+
{
109+
handlerIsValid = peer.CheckLogEnabled(NetIncomingMessageType.ErrorMessage);
110+
111+
if (handlerIsValid)
112+
Implementation = new DefaultInterpolatedStringHandler(literalLength, formattedCount);
61113
}
62114

63-
private void SendLogBase(NetIncomingMessageType type, string text)
115+
public void AppendLiteral(string value)
116+
=> Implementation.AppendLiteral(value);
117+
118+
public void AppendFormatted<T>(T t, int alignment = 0, string? format = null)
119+
=> Implementation.AppendFormatted(t, alignment, format);
120+
121+
public string ToStringAndClear() => Implementation.ToStringAndClear();
122+
}
123+
124+
[InterpolatedStringHandler]
125+
internal ref struct NetWarningLogInterpolatedStringHandler
126+
{
127+
public DefaultInterpolatedStringHandler Implementation;
128+
129+
public NetWarningLogInterpolatedStringHandler(
130+
int literalLength,
131+
int formattedCount,
132+
NetPeer peer,
133+
out bool handlerIsValid)
64134
{
65-
LogEvent?.Invoke(type, text);
135+
handlerIsValid = peer.CheckLogEnabled(NetIncomingMessageType.WarningMessage);
66136

67-
if (m_configuration.IsMessageTypeEnabled(type))
68-
ReleaseMessage(CreateIncomingMessage(type, text));
137+
if (handlerIsValid)
138+
Implementation = new DefaultInterpolatedStringHandler(literalLength, formattedCount);
69139
}
140+
141+
public void AppendLiteral(string value)
142+
=> Implementation.AppendLiteral(value);
143+
144+
public void AppendFormatted<T>(T t, int alignment = 0, string? format = null)
145+
=> Implementation.AppendFormatted(t, alignment, format);
146+
147+
public string ToStringAndClear() => Implementation.ToStringAndClear();
70148
}
71-
}
149+
#endif
150+
}

Lidgren.Network/NetPeer.MessagePools.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -199,7 +199,7 @@ internal void Recycle(NetOutgoingMessage msg)
199199
#if DEBUG
200200
NetException.Assert(m_outgoingMessagesPool.Contains(msg) == false, "Recyling already recycled outgoing message! Thread race?");
201201
if (msg.m_recyclingCount != 0)
202-
LogWarning("Wrong recycling count! should be zero; found " + msg.m_recyclingCount);
202+
LogWarning($"Wrong recycling count! should be zero; found {msg.m_recyclingCount}");
203203
#endif
204204
// setting m_recyclingCount to zero SHOULD be an unnecessary maneuver, if it's not zero something is wrong
205205
// however, in RELEASE, we'll just have to accept this and move on with life

Lidgren.Network/NetPeer.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -347,7 +347,8 @@ public virtual NetConnection Connect(NetEndPoint remoteEndPoint, NetOutgoingMess
347347
break;
348348
default:
349349
// weird
350-
LogWarning("Weird situation; Connect() already in progress to remote endpoint; but hs status is " + hs.m_status);
350+
LogWarning(
351+
$"Weird situation; Connect() already in progress to remote endpoint; but hs status is {hs.m_status}");
351352
break;
352353
}
353354
return hs;

Lidgren.Network/NetUPnP.cs

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -261,7 +261,7 @@ public bool ForwardPort(int externalPort, string description, int internalPort =
261261
}
262262
catch (Exception ex)
263263
{
264-
m_peer.LogWarning("UPnP port forward failed: " + ex.Message);
264+
m_peer.LogWarning($"UPnP port forward failed: {ex.Message}");
265265
return false;
266266
}
267267
return true;
@@ -292,7 +292,7 @@ public bool DeleteForwardingRule(int externalPort, string proto = "UDP")
292292
}
293293
catch (Exception ex)
294294
{
295-
m_peer.LogWarning("UPnP delete forwarding rule failed: " + ex.Message);
295+
m_peer.LogWarning($"UPnP delete forwarding rule failed: {ex.Message}");
296296
return false;
297297
}
298298
}
@@ -330,7 +330,7 @@ public bool DeleteForwardingRule(int externalPort, string proto = "UDP")
330330
}
331331
catch (Exception ex)
332332
{
333-
m_peer.LogWarning("Failed to get external IP: " + ex.Message);
333+
m_peer.LogWarning($"Failed to get external IP: {ex.Message}");
334334
return null;
335335
}
336336
}
@@ -357,7 +357,7 @@ public bool DeleteForwardingRule(int externalPort, string proto = "UDP")
357357
}
358358
catch (Exception ex)
359359
{
360-
m_peer.LogWarning("Failed to get connection status: " + ex.Message);
360+
m_peer.LogWarning($"Failed to get connection status: {ex.Message}");
361361
return null;
362362
}
363363
}

Lidgren.Network/NetUnreliableSenderChannel.cs

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -63,9 +63,7 @@ internal override NetSendResult Enqueue(NetOutgoingMessage message)
6363
{
6464
// drop message
6565
this.m_connection.m_peer.LogError(
66-
string.Format("Unreliable message max size exceeded: {0} bits (max {1})",
67-
message.LengthBits,
68-
ushort.MaxValue));
66+
$"Unreliable message max size exceeded: {message.LengthBits} bits (max {ushort.MaxValue})");
6967
return NetSendResult.Dropped;
7068
}
7169

RELEASE-NOTES.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
## Master
44

55
- Revert change to `NetPeer.Connections` so it returns a `List<>` instead of `IReadOnlyList<>` again. Change was introduced in 0.2.7.
6+
- Overhead introduced by warning/error logs is now almost completely gone when they are disabled.
67

78
## 0.3.0
89

0 commit comments

Comments
 (0)