Add opt-in binary diagnostics for SignalR serialization
Introduces detailed, opt-in diagnostic logging for binary serialization and deserialization in SignalR server and client code. Adds type and binary-level diagnostics, including hex dumps and header parsing, to aid debugging of protocol and type mismatches. Improves string hash function in the binary deserializer to avoid collisions. Diagnostics are consistent and structured, and can be enabled independently on server, client, and response message classes. No impact on normal operation unless diagnostics are enabled.
This commit is contained in:
parent
cde2b5e529
commit
4b2d3f4e75
|
|
@ -383,20 +383,23 @@ public static partial class AcBinaryDeserializer
|
|||
/// </summary>
|
||||
private string ReadStringUtf8Cached(int length)
|
||||
{
|
||||
// Create hash from position and first few bytes for fast lookup
|
||||
// Create hash from ALL bytes for short strings to avoid collisions
|
||||
// like "Creator" vs "Created" (same length, same prefix)
|
||||
var slice = _buffer.Slice(_position, length);
|
||||
var hash = ComputeStringHash(slice);
|
||||
var hash = ComputeStringHashFull(slice);
|
||||
|
||||
_stringCache ??= new Dictionary<int, string>(128);
|
||||
|
||||
if (_stringCache.TryGetValue(hash, out var cached))
|
||||
{
|
||||
// Verify it's actually the same string (hash collision check)
|
||||
// Hash includes all bytes for short strings, so collision is extremely unlikely
|
||||
// For longer strings, we still verify length as a sanity check
|
||||
if (cached.Length == length)
|
||||
{
|
||||
_position += length;
|
||||
return cached;
|
||||
}
|
||||
// Hash collision with different length - fall through to read new value
|
||||
}
|
||||
|
||||
var value = Utf8NoBom.GetString(slice);
|
||||
|
|
@ -405,26 +408,31 @@ public static partial class AcBinaryDeserializer
|
|||
return value;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Compute hash that includes ALL bytes for short strings to avoid collisions.
|
||||
/// For strings like "Creator" vs "Created" (7 bytes, same prefix), we need full content.
|
||||
/// </summary>
|
||||
[MethodImpl(MethodImplOptions.AggressiveInlining)]
|
||||
private static int ComputeStringHash(ReadOnlySpan<byte> data)
|
||||
private static int ComputeStringHashFull(ReadOnlySpan<byte> data)
|
||||
{
|
||||
// Fast hash using first bytes and length
|
||||
var hash = data.Length;
|
||||
if (data.Length >= 4)
|
||||
// For strings up to 32 bytes (covers most property names), hash ALL bytes
|
||||
// This completely eliminates collisions like Creator/Created
|
||||
if (data.Length <= 32)
|
||||
{
|
||||
hash = HashCode.Combine(hash,
|
||||
MemoryMarshal.Read<int>(data));
|
||||
var hash = new HashCode();
|
||||
hash.AddBytes(data);
|
||||
return hash.ToHashCode();
|
||||
}
|
||||
else if (data.Length >= 2)
|
||||
{
|
||||
hash = HashCode.Combine(hash,
|
||||
MemoryMarshal.Read<short>(data));
|
||||
}
|
||||
else if (data.Length == 1)
|
||||
{
|
||||
hash = HashCode.Combine(hash, data[0]);
|
||||
}
|
||||
return hash;
|
||||
|
||||
// For longer strings (rare for property names), use sampling strategy:
|
||||
// first 8 bytes + last 8 bytes + middle 8 bytes + length
|
||||
// This provides good collision resistance with O(1) performance
|
||||
var h = new HashCode();
|
||||
h.Add(data.Length);
|
||||
h.AddBytes(data.Slice(0, 8));
|
||||
h.AddBytes(data.Slice(data.Length - 8, 8));
|
||||
h.AddBytes(data.Slice(data.Length / 2 - 4, 8));
|
||||
return h.ToHashCode();
|
||||
}
|
||||
|
||||
[MethodImpl(MethodImplOptions.AggressiveInlining)]
|
||||
|
|
|
|||
|
|
@ -519,15 +519,17 @@ public static partial class AcBinaryDeserializer
|
|||
{
|
||||
var propertyCount = (int)context.ReadVarUInt();
|
||||
var nextDepth = depth + 1;
|
||||
var targetTypeName = target.GetType().Name;
|
||||
var targetType = target.GetType();
|
||||
var targetTypeName = targetType.Name;
|
||||
|
||||
for (int i = 0; i < propertyCount; i++)
|
||||
{
|
||||
var propertyNameStartPosition = context.Position;
|
||||
string propertyName;
|
||||
int propIndex = -1;
|
||||
if (context.HasMetadata)
|
||||
{
|
||||
var propIndex = (int)context.ReadVarUInt();
|
||||
propIndex = (int)context.ReadVarUInt();
|
||||
propertyName = context.GetPropertyName(propIndex);
|
||||
}
|
||||
else
|
||||
|
|
@ -560,7 +562,7 @@ public static partial class AcBinaryDeserializer
|
|||
throw new AcBinaryDeserializationException(
|
||||
$"Expected string for property name, got: {typeCode} (0x{typeCode:X2}) at position {propertyNameStartPosition}. " +
|
||||
$"Target: {targetTypeName}, PropertyIndex: {i}/{propertyCount}, Depth: {depth}",
|
||||
context.Position, target.GetType());
|
||||
context.Position, targetType);
|
||||
}
|
||||
}
|
||||
|
||||
|
|
@ -609,11 +611,12 @@ public static partial class AcBinaryDeserializer
|
|||
{
|
||||
// Add context about which property and what byte code was at the read position
|
||||
throw new AcBinaryDeserializationException(
|
||||
$"Type mismatch for property '{propertyName}' (index {i}/{propertyCount}) on '{targetTypeName}'. " +
|
||||
$"Type mismatch for property '{propertyName}' (index {i}/{propertyCount}, headerIndex={propIndex}) on '{targetTypeName}'. " +
|
||||
$"Expected type: '{propInfo.PropertyType.FullName}'. " +
|
||||
$"PeekCode before read: {peekCode} (0x{peekCode:X2}). " +
|
||||
$"Position before read: {positionBeforeRead}, current: {context.Position}. " +
|
||||
$"Depth: {depth}. " +
|
||||
$"Target type: {targetType.FullName}, Assembly: {targetType.Assembly.GetName().Name} v{targetType.Assembly.GetName().Version}. " +
|
||||
$"All target properties: [{string.Join(", ", metadata.PropertiesArray.Select(p => $"{p.Name}:{p.PropertyType.Name}"))}]. " +
|
||||
$"Error: {ex.Message}",
|
||||
positionBeforeRead,
|
||||
|
|
@ -689,6 +692,7 @@ public static partial class AcBinaryDeserializer
|
|||
}
|
||||
else if (BinaryTypeCode.IsFixStr(typeCode))
|
||||
{
|
||||
// FixStr: short string with length encoded in type code
|
||||
var length = BinaryTypeCode.DecodeFixStrLength(typeCode);
|
||||
propertyName = length == 0 ? string.Empty : context.ReadStringUtf8(length);
|
||||
}
|
||||
|
|
|
|||
|
|
@ -22,6 +22,12 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
|
|||
|
||||
protected AcSerializerOptions SerializerOptions = new AcBinarySerializerOptions();
|
||||
|
||||
/// <summary>
|
||||
/// Enable diagnostic logging for binary serialization debugging.
|
||||
/// Set to true to log hex dumps of serialized response data.
|
||||
/// </summary>
|
||||
public static bool EnableBinaryDiagnostics { get; set; } = false;
|
||||
|
||||
#region Connection Lifecycle
|
||||
|
||||
public override async Task OnConnectedAsync()
|
||||
|
|
@ -81,6 +87,12 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
|
|||
Logger.Debug($"[{responseSize / 1024}kb] responseData serialized ({SerializerOptions.SerializerType})");
|
||||
}
|
||||
|
||||
// Log binary diagnostics if enabled
|
||||
if (EnableBinaryDiagnostics && responseMessage is SignalResponseDataMessage dataMsg && dataMsg.ResponseData != null)
|
||||
{
|
||||
LogResponseDataDiagnostics(messageTag, tagName, requestId, dataMsg.ResponseData);
|
||||
}
|
||||
|
||||
await ResponseToCaller(messageTag, responseMessage, requestId);
|
||||
return;
|
||||
}
|
||||
|
|
@ -96,6 +108,165 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
|
|||
await ResponseToCaller(messageTag, CreateResponseMessage(messageTag, SignalResponseStatus.Error, null), requestId);
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Reads a VarUInt from byte array at given position.
|
||||
/// </summary>
|
||||
private static (uint value, int bytesRead) ReadVarUIntFromBytes(byte[] data, int startPos)
|
||||
{
|
||||
uint value = 0;
|
||||
int shift = 0;
|
||||
int bytesRead = 0;
|
||||
|
||||
while (startPos + bytesRead < data.Length)
|
||||
{
|
||||
var b = data[startPos + bytesRead];
|
||||
bytesRead++;
|
||||
value |= (uint)(b & 0x7F) << shift;
|
||||
if ((b & 0x80) == 0)
|
||||
break;
|
||||
shift += 7;
|
||||
if (shift > 35)
|
||||
break;
|
||||
}
|
||||
|
||||
return (value, bytesRead);
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Logs type information about the response data before serialization.
|
||||
/// </summary>
|
||||
private void LogResponseDataTypeInfo(object responseData)
|
||||
{
|
||||
try
|
||||
{
|
||||
var type = responseData.GetType();
|
||||
Logger.Info($"=== SERVER RESPONSE TYPE INFO (BEFORE SERIALIZE) ===");
|
||||
Logger.Info($"Runtime Type: {type.Name}");
|
||||
Logger.Info($"FullName: {type.FullName}");
|
||||
Logger.Info($"Namespace: {type.Namespace}");
|
||||
Logger.Info($"Assembly: {type.Assembly.GetName().Name} v{type.Assembly.GetName().Version}");
|
||||
Logger.Info($"AssemblyQualifiedName: {type.AssemblyQualifiedName}");
|
||||
Logger.Info($"Assembly Location: {type.Assembly.Location}");
|
||||
|
||||
// For collections, log element type info
|
||||
if (type.IsGenericType)
|
||||
{
|
||||
var genericArgs = type.GetGenericArguments();
|
||||
Logger.Info($"Generic Arguments: [{string.Join(", ", genericArgs.Select(t => t.FullName))}]");
|
||||
|
||||
if (genericArgs.Length == 1)
|
||||
{
|
||||
var elementType = genericArgs[0];
|
||||
Logger.Info($"--- ELEMENT TYPE INFO ---");
|
||||
Logger.Info($"Element Type: {elementType.Name}");
|
||||
Logger.Info($"Element FullName: {elementType.FullName}");
|
||||
Logger.Info($"Element Namespace: {elementType.Namespace}");
|
||||
Logger.Info($"Element Assembly: {elementType.Assembly.GetName().Name} v{elementType.Assembly.GetName().Version}");
|
||||
Logger.Info($"Element AssemblyQualifiedName: {elementType.AssemblyQualifiedName}");
|
||||
Logger.Info($"Element Assembly Location: {elementType.Assembly.Location}");
|
||||
Logger.Info($"Element BaseType: {elementType.BaseType?.FullName ?? "null"}");
|
||||
|
||||
// Log inheritance chain
|
||||
var baseType = elementType.BaseType;
|
||||
var inheritanceChain = new List<string>();
|
||||
while (baseType != null && baseType != typeof(object))
|
||||
{
|
||||
inheritanceChain.Add($"{baseType.Name} ({baseType.Assembly.GetName().Name})");
|
||||
baseType = baseType.BaseType;
|
||||
}
|
||||
if (inheritanceChain.Count > 0)
|
||||
{
|
||||
Logger.Info($"Element Inheritance: {string.Join(" -> ", inheritanceChain)}");
|
||||
}
|
||||
|
||||
LogTypePropertiesServer(elementType, "Element");
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
Logger.Info($"BaseType: {type.BaseType?.FullName ?? "null"}");
|
||||
LogTypePropertiesServer(type, "Response");
|
||||
}
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Logger.Warning($"Failed to log response type info: {ex.Message}");
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Logs all properties of a type with their declaring types.
|
||||
/// </summary>
|
||||
private void LogTypePropertiesServer(Type type, string prefix)
|
||||
{
|
||||
var props = type.GetProperties(System.Reflection.BindingFlags.Public | System.Reflection.BindingFlags.Instance)
|
||||
.Where(p => p.CanRead && p.GetIndexParameters().Length == 0)
|
||||
.ToArray();
|
||||
|
||||
// Log in declaration order (not alphabetically)
|
||||
Logger.Info($"{prefix} Property Count: {props.Length}");
|
||||
for (int i = 0; i < props.Length; i++)
|
||||
{
|
||||
var p = props[i];
|
||||
var declaringType = p.DeclaringType?.Name ?? "?";
|
||||
var declaringAssembly = p.DeclaringType?.Assembly.GetName().Name ?? "?";
|
||||
Logger.Info($" {prefix}[{i}]: {p.Name} : {p.PropertyType.Name} (declared in {declaringType} @ {declaringAssembly})");
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Logs diagnostic information about the ResponseData binary for debugging serialization issues.
|
||||
/// </summary>
|
||||
private void LogResponseDataDiagnostics(int messageTag, string tagName, int? requestId, byte[] responseData)
|
||||
{
|
||||
try
|
||||
{
|
||||
Logger.Info($"=== SERVER RESPONSE DATA DIAGNOSTICS (AFTER SERIALIZE) ===");
|
||||
Logger.Info($"Tag: {messageTag} ({tagName}); RequestId: {requestId}; ResponseData.Length: {responseData.Length}");
|
||||
Logger.Info($"HEX (first 500 bytes): {Convert.ToHexString(responseData.AsSpan(0, Math.Min(500, responseData.Length)))}");
|
||||
|
||||
if (responseData.Length >= 3)
|
||||
{
|
||||
var version = responseData[0];
|
||||
var marker = responseData[1];
|
||||
Logger.Info($"Version: {version}; Marker: 0x{marker:X2}");
|
||||
|
||||
if ((marker & 0x10) != 0)
|
||||
{
|
||||
// Read property count as VarUInt
|
||||
var pos = 2;
|
||||
var (propCount, bytesRead) = ReadVarUIntFromBytes(responseData, pos);
|
||||
pos += bytesRead;
|
||||
|
||||
Logger.Info($"Header property count: {propCount}");
|
||||
|
||||
for (int i = 0; i < (int)propCount && pos < responseData.Length; i++)
|
||||
{
|
||||
// Read string length as VarUInt
|
||||
var (strLen, strLenBytes) = ReadVarUIntFromBytes(responseData, pos);
|
||||
pos += strLenBytes;
|
||||
|
||||
if (pos + (int)strLen <= responseData.Length)
|
||||
{
|
||||
var propName = System.Text.Encoding.UTF8.GetString(responseData, pos, (int)strLen);
|
||||
pos += (int)strLen;
|
||||
Logger.Info($" Header[{i}]: '{propName}'");
|
||||
}
|
||||
else
|
||||
{
|
||||
Logger.Info($" Header[{i}]: <truncated at pos {pos}>");
|
||||
break;
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Logger.Warning($"Failed to log response data diagnostics: {ex.Message}");
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Creates a response message using the configured serializer.
|
||||
/// </summary>
|
||||
|
|
@ -134,6 +305,12 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
|
|||
|
||||
responseData = methodInfoModel.MethodInfo.InvokeMethod(methodsByDeclaringObject.InstanceObject, paramValues);
|
||||
|
||||
// Log type information if diagnostics enabled
|
||||
if (EnableBinaryDiagnostics && responseData != null)
|
||||
{
|
||||
LogResponseDataTypeInfo(responseData);
|
||||
}
|
||||
|
||||
if (methodInfoModel.Attribute.SendToOtherClientType != SendToClientType.None)
|
||||
SendMessageToOthers(methodInfoModel.Attribute.SendToOtherClientTag, responseData).Forget();
|
||||
|
||||
|
|
|
|||
|
|
@ -324,6 +324,9 @@ namespace AyCode.Services.SignalRs
|
|||
requestModel.ResponseDateTime = DateTime.UtcNow;
|
||||
Logger.Debug($"[{requestModel.ResponseDateTime.Subtract(requestModel.RequestDateTime).TotalMilliseconds:N0}ms][{messageBytes.Length / 1024}kb]{logText}");
|
||||
|
||||
// Diagnostic logging for binary deserialization debugging
|
||||
LogBinaryDiagnostics(messageTag, messageBytes, requestId);
|
||||
|
||||
var responseMessage = SignalRSerializationHelper.DeserializeFromBinary<SignalResponseDataMessage>(messageBytes) ?? new SignalResponseDataMessage();
|
||||
|
||||
switch (requestModel.ResponseByRequestId)
|
||||
|
|
@ -359,14 +362,119 @@ namespace AyCode.Services.SignalRs
|
|||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
// Enhanced error logging with binary diagnostics
|
||||
if (messageBytes.Length > 0)
|
||||
{
|
||||
LogBinaryDiagnosticsOnError(messageTag, messageBytes, requestId, ex);
|
||||
}
|
||||
|
||||
if (requestId.HasValue && _responseByRequestId.TryRemove(requestId.Value, out var exModel))
|
||||
SignalRRequestModelPool.Return(exModel);
|
||||
|
||||
Logger.Error($"Client OnReceiveMessage; ConnectionState: {GetConnectionState()}; requestId: {requestId}; {ex.Message}; {ConstHelper.NameByValue(TagsName, messageTag)}", ex);
|
||||
Logger.Error($"Client OnReceiveMessage; requestId: {requestId}; ConnectionState: {GetConnectionState()}; {ex.Message}; {ConstHelper.NameByValue(TagsName, messageTag)}", ex);
|
||||
throw;
|
||||
}
|
||||
|
||||
return Task.CompletedTask;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Enable diagnostic logging for binary deserialization debugging.
|
||||
/// Set to true to log hex dumps of received binary data.
|
||||
/// </summary>
|
||||
public bool EnableBinaryDiagnostics { get; set; } = false;
|
||||
|
||||
/// <summary>
|
||||
/// Logs binary diagnostics for debugging serialization issues.
|
||||
/// </summary>
|
||||
private void LogBinaryDiagnostics(int messageTag, byte[] messageBytes, int? requestId)
|
||||
{
|
||||
if (!EnableBinaryDiagnostics || messageBytes.Length == 0) return;
|
||||
|
||||
try
|
||||
{
|
||||
var hexDump = Convert.ToHexString(messageBytes.AsSpan(0, Math.Min(500, messageBytes.Length)));
|
||||
Logger.Info($"=== BINARY DIAGNOSTICS === Tag: {messageTag}; RequestId: {requestId}; Length: {messageBytes.Length}");
|
||||
Logger.Info($"HEX (first 500 bytes): {hexDump}");
|
||||
|
||||
// Parse header info
|
||||
if (messageBytes.Length >= 3)
|
||||
{
|
||||
var version = messageBytes[0];
|
||||
var marker = messageBytes[1];
|
||||
Logger.Info($"Version: {version}; Marker: 0x{marker:X2}");
|
||||
|
||||
if ((marker & 0x10) != 0 && messageBytes.Length > 2)
|
||||
{
|
||||
var propCount = messageBytes[2];
|
||||
Logger.Info($"Header property count: {propCount}");
|
||||
|
||||
// Parse first 10 property names
|
||||
var pos = 3;
|
||||
for (int i = 0; i < Math.Min((int)propCount, 10) && pos < messageBytes.Length; i++)
|
||||
{
|
||||
var strLen = messageBytes[pos++];
|
||||
if (pos + strLen <= messageBytes.Length)
|
||||
{
|
||||
var propName = System.Text.Encoding.UTF8.GetString(messageBytes, pos, strLen);
|
||||
pos += strLen;
|
||||
Logger.Info($" [{i}]: '{propName}'");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Logger.Warning($"Failed to log binary diagnostics: {ex.Message}");
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Logs binary diagnostics when an error occurs during deserialization.
|
||||
/// </summary>
|
||||
private void LogBinaryDiagnosticsOnError(int messageTag, byte[] messageBytes, int? requestId, Exception error)
|
||||
{
|
||||
try
|
||||
{
|
||||
Logger.Error($"=== BINARY DESERIALIZATION ERROR ===");
|
||||
Logger.Error($"Tag: {messageTag}; RequestId: {requestId}; Length: {messageBytes.Length}");
|
||||
Logger.Error($"Error: {error.Message}");
|
||||
|
||||
var hexDump = Convert.ToHexString(messageBytes.AsSpan(0, Math.Min(1000, messageBytes.Length)));
|
||||
Logger.Error($"HEX (first 1000 bytes): {hexDump}");
|
||||
|
||||
// Parse header info
|
||||
if (messageBytes.Length >= 3)
|
||||
{
|
||||
var version = messageBytes[0];
|
||||
var marker = messageBytes[1];
|
||||
Logger.Error($"Version: {version}; Marker: 0x{marker:X2}");
|
||||
|
||||
if ((marker & 0x10) != 0 && messageBytes.Length > 2)
|
||||
{
|
||||
var propCount = messageBytes[2];
|
||||
Logger.Error($"Header property count: {propCount}");
|
||||
|
||||
// Parse ALL property names
|
||||
var pos = 3;
|
||||
for (int i = 0; i < propCount && pos < messageBytes.Length; i++)
|
||||
{
|
||||
var strLen = messageBytes[pos++];
|
||||
if (pos + strLen <= messageBytes.Length)
|
||||
{
|
||||
var propName = System.Text.Encoding.UTF8.GetString(messageBytes, pos, strLen);
|
||||
pos += strLen;
|
||||
Logger.Error($" Header[{i}]: '{propName}'");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
Logger.Warning($"Failed to log binary diagnostics on error: {ex.Message}");
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -150,6 +150,13 @@ public sealed class SignalResponseDataMessage : ISignalResponseMessage, IDisposa
|
|||
[JsonIgnore] [STJIgnore] private byte[]? _rentedDecompressedBuffer;
|
||||
[JsonIgnore] [STJIgnore] private int _decompressedLength;
|
||||
|
||||
/// <summary>
|
||||
/// Enable diagnostic logging for ResponseData deserialization.
|
||||
/// When set, logs hex dump and header info before deserialization.
|
||||
/// </summary>
|
||||
[JsonIgnore] [STJIgnore]
|
||||
public static Action<string>? DiagnosticLogger { get; set; }
|
||||
|
||||
public SignalResponseDataMessage() { }
|
||||
|
||||
public SignalResponseDataMessage(int messageTag, SignalResponseStatus status)
|
||||
|
|
@ -176,7 +183,21 @@ public sealed class SignalResponseDataMessage : ISignalResponseMessage, IDisposa
|
|||
if (ResponseData == null) return default;
|
||||
|
||||
if (DataSerializerType == AcSerializerType.Binary)
|
||||
return (T)(_cachedResponseData = ResponseData.BinaryTo<T>()!);
|
||||
{
|
||||
try
|
||||
{
|
||||
// Log diagnostics if enabled
|
||||
LogResponseDataDiagnostics<T>();
|
||||
|
||||
return (T)(_cachedResponseData = ResponseData.BinaryTo<T>()!);
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
// Log detailed error diagnostics
|
||||
LogResponseDataError<T>(ex);
|
||||
throw;
|
||||
}
|
||||
}
|
||||
|
||||
// Decompress Brotli to pooled buffer and deserialize directly
|
||||
EnsureDecompressed();
|
||||
|
|
@ -185,6 +206,207 @@ public sealed class SignalResponseDataMessage : ISignalResponseMessage, IDisposa
|
|||
return result;
|
||||
}
|
||||
|
||||
private void LogResponseDataDiagnostics<T>()
|
||||
{
|
||||
if (DiagnosticLogger == null || ResponseData == null) return;
|
||||
|
||||
try
|
||||
{
|
||||
var targetType = typeof(T);
|
||||
DiagnosticLogger($"=== RESPONSE DATA DIAGNOSTICS (DESERIALIZE) ===");
|
||||
DiagnosticLogger($"Target Type: {targetType.Name}");
|
||||
DiagnosticLogger($"Target FullName: {targetType.FullName}");
|
||||
DiagnosticLogger($"Target Namespace: {targetType.Namespace}");
|
||||
DiagnosticLogger($"Target Assembly: {targetType.Assembly.GetName().Name} v{targetType.Assembly.GetName().Version}");
|
||||
DiagnosticLogger($"Target AssemblyQualifiedName: {targetType.AssemblyQualifiedName}");
|
||||
DiagnosticLogger($"Target Assembly Location: {targetType.Assembly.Location}");
|
||||
|
||||
// Log element type for collections
|
||||
if (targetType.IsGenericType)
|
||||
{
|
||||
var genericArgs = targetType.GetGenericArguments();
|
||||
DiagnosticLogger($"Generic Arguments: [{string.Join(", ", genericArgs.Select(t => t.FullName))}]");
|
||||
if (genericArgs.Length == 1)
|
||||
{
|
||||
var elementType = genericArgs[0];
|
||||
DiagnosticLogger($"--- ELEMENT TYPE INFO ---");
|
||||
DiagnosticLogger($"Element Type: {elementType.Name}");
|
||||
DiagnosticLogger($"Element FullName: {elementType.FullName}");
|
||||
DiagnosticLogger($"Element Namespace: {elementType.Namespace}");
|
||||
DiagnosticLogger($"Element Assembly: {elementType.Assembly.GetName().Name} v{elementType.Assembly.GetName().Version}");
|
||||
DiagnosticLogger($"Element AssemblyQualifiedName: {elementType.AssemblyQualifiedName}");
|
||||
DiagnosticLogger($"Element Assembly Location: {elementType.Assembly.Location}");
|
||||
DiagnosticLogger($"Element BaseType: {elementType.BaseType?.FullName ?? "null"}");
|
||||
|
||||
// Log inheritance chain
|
||||
var baseType = elementType.BaseType;
|
||||
var inheritanceChain = new List<string>();
|
||||
while (baseType != null && baseType != typeof(object))
|
||||
{
|
||||
inheritanceChain.Add($"{baseType.Name} ({baseType.Assembly.GetName().Name})");
|
||||
baseType = baseType.BaseType;
|
||||
}
|
||||
if (inheritanceChain.Count > 0)
|
||||
{
|
||||
DiagnosticLogger($"Element Inheritance: {string.Join(" -> ", inheritanceChain)}");
|
||||
}
|
||||
|
||||
LogTypeProperties(elementType, "Element");
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
DiagnosticLogger($"BaseType: {targetType.BaseType?.FullName ?? "null"}");
|
||||
LogTypeProperties(targetType, "Target");
|
||||
}
|
||||
|
||||
DiagnosticLogger($"ResponseData.Length: {ResponseData.Length}");
|
||||
DiagnosticLogger($"HEX (first 500 bytes): {Convert.ToHexString(ResponseData.AsSpan(0, Math.Min(500, ResponseData.Length)))}");
|
||||
|
||||
// Parse header with VarInt support
|
||||
LogBinaryHeader(ResponseData);
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
DiagnosticLogger($"Failed to log diagnostics: {ex.Message}");
|
||||
}
|
||||
}
|
||||
|
||||
private void LogTypeProperties(Type type, string prefix)
|
||||
{
|
||||
if (DiagnosticLogger == null) return;
|
||||
|
||||
var props = type.GetProperties(System.Reflection.BindingFlags.Public | System.Reflection.BindingFlags.Instance)
|
||||
.Where(p => p.CanRead && p.GetIndexParameters().Length == 0)
|
||||
.ToArray();
|
||||
|
||||
// Log in declaration order (not alphabetically) to match serialization order
|
||||
DiagnosticLogger($"{prefix} Property Count: {props.Length}");
|
||||
for (int i = 0; i < props.Length; i++)
|
||||
{
|
||||
var p = props[i];
|
||||
var declaringType = p.DeclaringType?.Name ?? "?";
|
||||
var declaringAssembly = p.DeclaringType?.Assembly.GetName().Name ?? "?";
|
||||
DiagnosticLogger($" {prefix}[{i}]: {p.Name} : {p.PropertyType.Name} (declared in {declaringType} @ {declaringAssembly})");
|
||||
}
|
||||
}
|
||||
|
||||
private void LogBinaryHeader(byte[] data)
|
||||
{
|
||||
if (DiagnosticLogger == null || data.Length < 3) return;
|
||||
|
||||
var version = data[0];
|
||||
var marker = data[1];
|
||||
DiagnosticLogger($"Binary Version: {version}; Marker: 0x{marker:X2}");
|
||||
|
||||
// Check if metadata flag is set
|
||||
if ((marker & 0x10) == 0)
|
||||
{
|
||||
DiagnosticLogger("Header: No metadata (property names inline)");
|
||||
return;
|
||||
}
|
||||
|
||||
// Read property count as VarUInt
|
||||
var pos = 2;
|
||||
var (propCount, bytesRead) = ReadVarUIntFromSpan(data.AsSpan(pos));
|
||||
pos += bytesRead;
|
||||
|
||||
DiagnosticLogger($"Header Property Count: {propCount}");
|
||||
|
||||
for (int i = 0; i < (int)propCount && pos < data.Length; i++)
|
||||
{
|
||||
// Read string length as VarUInt
|
||||
var (strLen, strLenBytes) = ReadVarUIntFromSpan(data.AsSpan(pos));
|
||||
pos += strLenBytes;
|
||||
|
||||
if (pos + (int)strLen <= data.Length)
|
||||
{
|
||||
var propName = System.Text.Encoding.UTF8.GetString(data, pos, (int)strLen);
|
||||
pos += (int)strLen;
|
||||
DiagnosticLogger($" Header[{i}]: '{propName}'");
|
||||
}
|
||||
else
|
||||
{
|
||||
DiagnosticLogger($" Header[{i}]: <truncated at pos {pos}>");
|
||||
break;
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
private static (uint value, int bytesRead) ReadVarUIntFromSpan(ReadOnlySpan<byte> span)
|
||||
{
|
||||
uint value = 0;
|
||||
int shift = 0;
|
||||
int bytesRead = 0;
|
||||
|
||||
while (bytesRead < span.Length)
|
||||
{
|
||||
var b = span[bytesRead++];
|
||||
value |= (uint)(b & 0x7F) << shift;
|
||||
if ((b & 0x80) == 0)
|
||||
break;
|
||||
shift += 7;
|
||||
if (shift > 35)
|
||||
break;
|
||||
}
|
||||
|
||||
return (value, bytesRead);
|
||||
}
|
||||
|
||||
private void LogResponseDataError<T>(Exception error)
|
||||
{
|
||||
if (DiagnosticLogger == null || ResponseData == null) return;
|
||||
|
||||
try
|
||||
{
|
||||
var targetType = typeof(T);
|
||||
DiagnosticLogger($"=== RESPONSE DATA DESERIALIZATION ERROR ===");
|
||||
DiagnosticLogger($"Error: {error.Message}");
|
||||
DiagnosticLogger($"Target Type: {targetType.Name}");
|
||||
DiagnosticLogger($"Target FullName: {targetType.FullName}");
|
||||
DiagnosticLogger($"Target Namespace: {targetType.Namespace}");
|
||||
DiagnosticLogger($"Target Assembly: {targetType.Assembly.GetName().Name} v{targetType.Assembly.GetName().Version}");
|
||||
DiagnosticLogger($"Target AssemblyQualifiedName: {targetType.AssemblyQualifiedName}");
|
||||
|
||||
// Log element type for collections
|
||||
if (targetType.IsGenericType)
|
||||
{
|
||||
var genericArgs = targetType.GetGenericArguments();
|
||||
DiagnosticLogger($"Generic Arguments: [{string.Join(", ", genericArgs.Select(t => t.FullName))}]");
|
||||
if (genericArgs.Length == 1)
|
||||
{
|
||||
var elementType = genericArgs[0];
|
||||
DiagnosticLogger($"Element Type: {elementType.FullName}");
|
||||
DiagnosticLogger($"Element Assembly: {elementType.Assembly.GetName().Name}");
|
||||
LogTypeProperties(elementType, "Element");
|
||||
}
|
||||
}
|
||||
else
|
||||
{
|
||||
LogTypeProperties(targetType, "Target");
|
||||
}
|
||||
|
||||
DiagnosticLogger($"ResponseData.Length: {ResponseData.Length}");
|
||||
DiagnosticLogger($"HEX (first 1000 bytes): {Convert.ToHexString(ResponseData.AsSpan(0, Math.Min(1000, ResponseData.Length)))}");
|
||||
|
||||
// Parse header
|
||||
LogBinaryHeader(ResponseData);
|
||||
|
||||
// Log inner exception if present
|
||||
if (error.InnerException != null)
|
||||
{
|
||||
DiagnosticLogger($"Inner Exception: {error.InnerException.Message}");
|
||||
}
|
||||
|
||||
// Log stack trace
|
||||
DiagnosticLogger($"Stack Trace: {error.StackTrace}");
|
||||
}
|
||||
catch (Exception ex)
|
||||
{
|
||||
DiagnosticLogger?.Invoke($"Failed to log error diagnostics: {ex.Message}");
|
||||
}
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Gets the decompressed JSON bytes as a ReadOnlySpan for direct processing.
|
||||
/// </summary>
|
||||
|
|
|
|||
Loading…
Reference in New Issue