fix: Adds packet logging (#836)

### Enabling Packet Logging
`[packetlogging on` and target the user.
Supports command modifiers such as:
`[online packetlogging on where accesslevel = player`

Logs are saved in `path/<ip address>/packets.log`. It is a simple append-format log with no date splitting.
This commit is contained in:
Kamron Batman 2021-10-31 10:22:22 -07:00 committed by GitHub
parent 85d699fcd7
commit 2890f5c3ec
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 186 additions and 193 deletions

View file

@ -129,7 +129,7 @@ namespace System.Buffers
public Span<T> GetSpan(int index)
{
if (index < 0 || index > 1)
if (index is < 0 or > 1)
{
throw new ArgumentOutOfRangeException(nameof(index));
}

View file

@ -32,6 +32,10 @@ namespace Server.Network
public int Position { get; private set; }
public int Remaining => Length - Position;
// Only used for debugging!
public ReadOnlySpan<byte> First => _first;
public ReadOnlySpan<byte> Second => _second;
public CircularBufferReader(ref CircularBuffer<byte> buffer) : this(buffer.GetSpan(0), buffer.GetSpan(1))
{
}
@ -58,12 +62,9 @@ namespace Server.Network
try
{
using var sw = new StreamWriter("Packets.log", true);
using var sw = new StreamWriter("unhandled-packets.log", true);
sw.WriteLine("Client: {0}: Unhandled packet 0x{1:X2}", state, _first[0]);
Utility.FormatBuffer(sw, _first.ToArray(), new Memory<byte>(_second.ToArray()));
sw.FormatBuffer(_first, _second, Length);
sw.WriteLine();
sw.WriteLine();
}

View file

@ -73,6 +73,7 @@ namespace Server.Network
internal ParserState _parserState = ParserState.AwaitingNextPacket;
internal ProtocolState _protocolState = ProtocolState.AwaitingSeed;
internal GCHandle _handle;
private bool _packetLogging;
internal enum ParserState
{
@ -97,6 +98,13 @@ namespace Server.Network
Error
}
private static string _packetLoggingPath;
public static void Configure()
{
_packetLoggingPath = ServerConfiguration.GetSetting("netstate.packetLoggingPath", Path.Combine(Core.BaseDirectory, "Packets"));
}
public static void Initialize()
{
Timer.DelayCall(TimeSpan.FromMinutes(1), TimeSpan.FromMinutes(1.5), CheckAllAlive);
@ -142,6 +150,21 @@ namespace Server.Network
CreatedCallback?.Invoke(this);
}
// Only use this for debugging. This will make your server very slow!
public bool PacketLogging
{
get => _packetLogging;
set
{
_packetLogging = value;
if (_packetLogging)
{
StartPacketLog();
}
}
}
public DateTime ConnectedOn { get; }
public TimeSpan ConnectedFor => Core.Now - ConnectedOn;
@ -486,6 +509,11 @@ namespace Server.Network
buffer.CopyFrom(span);
}
if (PacketLogging)
{
LogPacket(span, ReadOnlySpan<byte>.Empty, span.Length, false);
}
SendPipe.Writer.Advance((uint)length);
if (!_flushQueued)
@ -506,6 +534,48 @@ namespace Server.Network
}
}
private void StartPacketLog()
{
try
{
var logDir = Path.Combine(_packetLoggingPath, _toString);
PathUtility.EnsureDirectory(logDir);
var logPath = Path.Combine(logDir, "packets.log");
using var op = new StreamWriter(logPath, true);
op.WriteLine(">>>>>>>>>> Logging started {0:yyyy/MM/dd HH:mm::ss} <<<<<<<<<<", Core.Now);
op.WriteLine();
op.WriteLine();
}
catch (Exception e)
{
Console.WriteLine(e);
}
}
private void LogPacket(ReadOnlySpan<byte> first, ReadOnlySpan<byte> second, int totalLength, bool incoming)
{
try
{
var logDir = Path.Combine(_packetLoggingPath, _toString);
PathUtility.EnsureDirectory(logDir);
var logPath = Path.Combine(logDir, "packets.log");
const string incomingStr = "Client -> Server";
const string outgoingStr = "Server -> Client";
using var sw = new StreamWriter(logPath, true);
sw.WriteLine($"{Core.Now:HH:mm:ss.ffff}: {(incoming ? incomingStr : outgoingStr)} 0x{first[0]:X2} (Length: {totalLength})");
sw.FormatBuffer(first, second, totalLength);
sw.WriteLine();
sw.WriteLine();
}
catch
{
// ignored
}
}
public void HandleReceive()
{
if (!_running)
@ -760,6 +830,11 @@ namespace Server.Network
UpdatePacketCount(packetId);
if (PacketLogging)
{
LogPacket(packetReader.First, packetReader.Second, packetLength, true);
}
handler.OnReceive(this, packetReader, ref packetLength);
prof?.Finish(packetLength);

View file

@ -59,6 +59,27 @@ namespace Server.Text
return result;
}
public static unsafe int ToSpacedHexString(this ReadOnlySpan<byte> bytes, Span<char> result)
{
var charsWritten = 0;
fixed (char* resultP = result)
{
for (int i = 0; i < bytes.Length; i++)
{
var resultP2 = (uint*)(resultP + charsWritten);
*resultP2 = m_Lookup32Chars[bytes[i]];
charsWritten += 2;
if (i < bytes.Length - 1)
{
*(resultP + charsWritten++) = ' ';
}
}
}
return charsWritten;
}
public static string ToDelimitedHexString(this byte[] bytes) => ((ReadOnlySpan<byte>)bytes).ToDelimitedHexString();
public static unsafe string ToDelimitedHexString(this ReadOnlySpan<byte> bytes)

View file

@ -11,6 +11,7 @@ using System.Xml;
using Microsoft.Toolkit.HighPerformance;
using Server.Buffers;
using Server.Random;
using Server.Text;
namespace Server
{
@ -632,207 +633,42 @@ namespace Server
}
}
public static void FormatBuffer(TextWriter output, Stream input, int length)
public static void FormatBuffer(this TextWriter op, ReadOnlySpan<byte> first, ReadOnlySpan<byte> second, int totalLength)
{
output.WriteLine(" 0 1 2 3 4 5 6 7 8 9 A B C D E F");
output.WriteLine(" -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --");
op.WriteLine(" 0 1 2 3 4 5 6 7 8 9 A B C D E F");
op.WriteLine(" -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --");
var byteIndex = 0;
var whole = length >> 4;
var rem = length & 0xF;
for (var i = 0; i < whole; ++i, byteIndex += 16)
if (totalLength <= 0)
{
var bytes = new StringBuilder(49);
var chars = new StringBuilder(16);
for (var j = 0; j < 16; ++j)
{
var c = input.ReadByte();
bytes.Append(c.ToString("X2"));
if (j != 7)
{
bytes.Append(' ');
}
else
{
bytes.Append(" ");
}
if (c >= 0x20 && c < 0x7F)
{
chars.Append((char)c);
}
else
{
chars.Append('.');
}
}
output.Write(byteIndex.ToString("X4"));
output.Write(" ");
output.Write(bytes.ToString());
output.Write(" ");
output.WriteLine(chars.ToString());
op.WriteLine("0000 ");
return;
}
if (rem != 0)
Span<byte> lineBytes = stackalloc byte[16];
Span<char> lineChars = stackalloc char[47];
for (var i = 0; i < totalLength; i += 16)
{
var bytes = new StringBuilder(49);
var chars = new StringBuilder(rem);
for (var j = 0; j < 16; ++j)
var length = Math.Min(totalLength - i, 16);
if (i < first.Length)
{
if (j < rem)
var firstLength = Math.Min(length, first.Length - i);
first.Slice(i, firstLength).CopyTo(lineBytes);
if (firstLength < length)
{
var c = input.ReadByte();
bytes.Append(c.ToString("X2"));
if (j != 7)
{
bytes.Append(' ');
}
else
{
bytes.Append(" ");
}
if (c >= 0x20 && c < 0x7F)
{
chars.Append((char)c);
}
else
{
chars.Append('.');
}
}
else
{
bytes.Append(" ");
second[..(length - first.Length - i)].CopyTo(lineBytes[(length - firstLength)..]);
}
}
output.Write(byteIndex.ToString("X4"));
output.Write(" ");
output.Write(bytes.ToString());
output.Write(" ");
output.WriteLine(chars.ToString());
}
}
public static void FormatBuffer(TextWriter output, params Memory<byte>[] mems)
{
output.WriteLine(" 0 1 2 3 4 5 6 7 8 9 A B C D E F");
output.WriteLine(" -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- --");
var byteIndex = 0;
var length = 0;
for (var i = 0; i < mems.Length; i++)
{
length += mems[i].Length;
}
var position = 0;
var memIndex = 0;
var span = mems[memIndex].Span;
var whole = length >> 4;
var rem = length & 0xF;
for (var i = 0; i < whole; ++i, byteIndex += 16)
{
var bytes = new StringBuilder(49);
var chars = new StringBuilder(16);
for (var j = 0; j < 16; ++j)
else
{
var c = span[position++];
if (position > span.Length)
{
span = mems[memIndex++].Span;
position = 0;
}
bytes.Append(c.ToString("X2"));
if (j != 7)
{
bytes.Append(' ');
}
else
{
bytes.Append(" ");
}
if (c >= 0x20 && c < 0x7F)
{
chars.Append((char)c);
}
else
{
chars.Append('.');
}
second.Slice(i - first.Length, length).CopyTo(lineBytes);
}
output.Write(byteIndex.ToString("X4"));
output.Write(" ");
output.Write(bytes.ToString());
output.Write(" ");
output.WriteLine(chars.ToString());
}
var charsWritten = ((ReadOnlySpan<byte>)lineBytes[..length]).ToSpacedHexString(lineChars);
if (rem != 0)
{
var bytes = new StringBuilder(49);
var chars = new StringBuilder(rem);
for (var j = 0; j < 16; ++j)
{
if (j < rem)
{
var c = span[position++];
if (position > span.Length)
{
span = mems[memIndex++].Span;
position = 0;
}
bytes.Append(c.ToString("X2"));
if (j != 7)
{
bytes.Append(' ');
}
else
{
bytes.Append(" ");
}
if (c >= 0x20 && c < 0x7F)
{
chars.Append((char)c);
}
else
{
chars.Append('.');
}
}
else
{
bytes.Append(" ");
}
}
output.Write(byteIndex.ToString("X4"));
output.Write(" ");
output.Write(bytes.ToString());
output.Write(" ");
output.WriteLine(chars.ToString());
op.Write("{0:X4} ", i);
op.Write(lineChars[..charsWritten]);
op.WriteLine();
}
}

View file

@ -0,0 +1,60 @@
using Server.Commands;
using Server.Commands.Generic;
using Server.Mobiles;
namespace Server.Network
{
public class PacketLoggingCommand : BaseCommand
{
public static void Initialize()
{
TargetCommands.Register(new PacketLoggingCommand());
}
public PacketLoggingCommand()
{
AccessLevel = AccessLevel.Developer;
Commands = new[] { "PacketLogging" };
ObjectTypes = ObjectTypes.Mobiles;
Supports = CommandSupport.AllMobiles;
Usage = "PacketLogging <on|off>";
Description = "Enables or disables packet logging for a particular user until they disconnect.";
}
public override void Execute(CommandEventArgs e, object targeted)
{
if (e.Arguments.Length == 0)
{
LogFailure("Format: PacketLogging <on|off>");
return;
}
var from = e.Mobile;
var enable = Utility.ToBoolean(e.Arguments[0]);
if (targeted is not PlayerMobile pm)
{
LogFailure("That is not a player.");
}
else if (pm.NetState == null)
{
LogFailure("The player is not connected.");
}
else if (from != pm && from.AccessLevel < pm.AccessLevel)
{
LogFailure("You do not have the required access level to do this.");
}
else
{
pm.NetState.PacketLogging = enable;
var enabled = enable ? "enabled" : "disabled";
CommandLogging.WriteLine(
from,
$"{from.AccessLevel} {CommandLogging.Format(from)} {enabled} packet logging for {pm.Account.Username} ({pm.NetState})"
);
AddResponse($"Packet logging has been {enabled} for {pm.Account.Username} ({pm.NetState})");
}
}
}
}