Add diagnostics for binary SignalR serialization bugs

Enhances debugging of custom binary serialization/deserialization in SignalR by introducing DiagnosticLogger hooks in both AcBinaryDeserializer and AcBinaryHubProtocol. Adds DEBUG-only verification methods to compare array-based and multi-segment deserialization, as well as IBufferWriter and byte[] serialization outputs, logging mismatches for easier bug isolation. Diagnostic loggers are automatically integrated with the hub and client loggers. Also includes extra debug output and a commented workaround for a known serialization issue. Diagnostics are opt-in and only active in DEBUG builds.
This commit is contained in:
Loretta 2026-04-07 20:53:20 +02:00
parent 26c8cd85ce
commit d060508bd8
4 changed files with 132 additions and 0 deletions

View File

@ -3,6 +3,7 @@ using System.Buffers;
using System.Collections; using System.Collections;
using System.Collections.Concurrent; using System.Collections.Concurrent;
using System.Collections.Frozen; using System.Collections.Frozen;
using System.Diagnostics;
using System.Linq.Expressions; using System.Linq.Expressions;
using System.Reflection; using System.Reflection;
using System.Runtime.CompilerServices; using System.Runtime.CompilerServices;
@ -27,6 +28,12 @@ namespace AyCode.Core.Serializers.Binaries;
/// </summary> /// </summary>
public static partial class AcBinaryDeserializer public static partial class AcBinaryDeserializer
{ {
/// <summary>
/// Diagnostic logger for deserializer-level debugging (DEBUG builds only).
/// Set to non-null to log SequenceBinaryInput vs ArrayBinaryInput verification results.
/// </summary>
public static Action<string>? DiagnosticLogger { get; set; }
private static readonly ConcurrentDictionary<Type, TypeConversionInfo> TypeConversionCache = new(); private static readonly ConcurrentDictionary<Type, TypeConversionInfo> TypeConversionCache = new();
/// <summary> /// <summary>
@ -260,6 +267,7 @@ public static partial class AcBinaryDeserializer
if (data.IsSingleSegment && MemoryMarshal.TryGetArray(data.First, out var seg)) if (data.IsSingleSegment && MemoryMarshal.TryGetArray(data.First, out var seg))
return Deserialize<T>(seg.Array!, seg.Offset, seg.Count, options); return Deserialize<T>(seg.Array!, seg.Offset, seg.Count, options);
VerifyAgainstLinearized(data, typeof(T), options);
return DeserializeSequence<T, SequenceBinaryInput>(new SequenceBinaryInput(data), typeof(T), options); return DeserializeSequence<T, SequenceBinaryInput>(new SequenceBinaryInput(data), typeof(T), options);
} }
@ -279,6 +287,7 @@ public static partial class AcBinaryDeserializer
if (data.IsSingleSegment && MemoryMarshal.TryGetArray(data.First, out var seg2)) if (data.IsSingleSegment && MemoryMarshal.TryGetArray(data.First, out var seg2))
return Deserialize(seg2.Array!, seg2.Offset, seg2.Count, targetType, options); return Deserialize(seg2.Array!, seg2.Offset, seg2.Count, targetType, options);
VerifyAgainstLinearized(data, targetType, options);
return DeserializeSequence<SequenceBinaryInput>(new SequenceBinaryInput(data), targetType, options); return DeserializeSequence<SequenceBinaryInput>(new SequenceBinaryInput(data), targetType, options);
} }
@ -357,6 +366,36 @@ public static partial class AcBinaryDeserializer
} }
} }
/// <summary>
/// DEBUG-only verification: linearizes multi-segment data to byte[] and deserializes
/// with ArrayBinaryInput to determine if drift is caused by SequenceBinaryInput or by
/// the serialized data itself (generated reader / serializer bug).
///
/// Result: VERIFY_OK → SequenceBinaryInput is the culprit.
/// VERIFY_FAIL → bug is in serializer or generated reader (data itself is bad).
/// </summary>
[Conditional("DEBUG")]
private static void VerifyAgainstLinearized(ReadOnlySequence<byte> data, Type targetType, AcBinarySerializerOptions options)
{
if (DiagnosticLogger == null) return;
var bytes = data.ToArray();
var segmentCount = 0;
foreach (var _ in data) segmentCount++;
try
{
var result = Deserialize(bytes, targetType, options);
DiagnosticLogger($"[VERIFY_OK] ArrayBinaryInput succeeded for {targetType.Name}, " +
$"{bytes.Length} bytes, {segmentCount} segments → SequenceBinaryInput is suspect");
}
catch (Exception ex)
{
DiagnosticLogger($"[VERIFY_FAIL] ArrayBinaryInput ALSO FAILED for {targetType.Name}, " +
$"{bytes.Length} bytes, {segmentCount} segments: {ex.Message}");
}
}
/// <summary> /// <summary>
/// Deserialize Expression from binary data. /// Deserialize Expression from binary data.
/// </summary> /// </summary>

View File

@ -23,6 +23,22 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
protected TLogger Logger = logger; protected TLogger Logger = logger;
protected IConfiguration Configuration = configuration; protected IConfiguration Configuration = configuration;
// Static init: route protocol & deserializer diagnostics through AcLoggerBase
private static readonly object _diagnosticInitLock = new();
private static bool _diagnosticInitialized;
protected void InitDiagnosticLoggerIfNeeded()
{
if (_diagnosticInitialized) return;
lock (_diagnosticInitLock)
{
if (_diagnosticInitialized) return;
AcBinaryHubProtocol.DiagnosticLogger ??= msg => Logger.Debug(msg);
AcBinaryDeserializer.DiagnosticLogger ??= msg => Logger.Debug(msg);
_diagnosticInitialized = true;
}
}
protected AcSerializerOptions SerializerOptions = new AcBinarySerializerOptions(); protected AcSerializerOptions SerializerOptions = new AcBinarySerializerOptions();
/// <summary> /// <summary>
@ -35,6 +51,7 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
public override async Task OnConnectedAsync() public override async Task OnConnectedAsync()
{ {
InitDiagnosticLoggerIfNeeded();
Logger.Debug($"Server OnConnectedAsync; ConnectionId: {GetConnectionId()}; UserIdentifier: {GetUserIdentifier()}"); Logger.Debug($"Server OnConnectedAsync; ConnectionId: {GetConnectionId()}; UserIdentifier: {GetUserIdentifier()}");
LogContextUserNameAndId(); LogContextUserNameAndId();
await base.OnConnectedAsync(); await base.OnConnectedAsync();
@ -301,6 +318,10 @@ public abstract class AcWebSignalRHubBase<TSignalRTags, TLogger>(IConfiguration
: AyCode.Core.Compression.GzipHelper.Compress(responseData.ToJson()); : AyCode.Core.Compression.GzipHelper.Compress(responseData.ToJson());
} }
//responseData = AcBinarySerializer.Serialize(responseData);
// TODO: BWO serialize bug workaround — pre-serialize responseData to byte[] here so protocol uses
// byte[] fast-path, bypassing AcBinarySerializer.Serialize(value, IBufferWriter<byte>, options).
// Set isRawBytes = true so client deserializes via ArrayBinaryInput. Remove when BWO bug is fixed.
var signalParams = new SignalParams var signalParams = new SignalParams
{ {
Status = status, Status = status,

View File

@ -395,8 +395,11 @@ public class AcBinaryHubProtocol : IHubProtocol
private void WriteArgument(ref BufferWriterBinaryOutput bw, IBufferWriter<byte> output, object? value, ref int externalBytes) private void WriteArgument(ref BufferWriterBinaryOutput bw, IBufferWriter<byte> output, object? value, ref int externalBytes)
{ {
Debug.WriteLine($"WriteArgument invoked");
if (value is byte[] byteArray) if (value is byte[] byteArray)
{ {
Debug.WriteLine($"WriteArgument value is byte[] byteArray");
// byte[] fast-path: size known upfront, write entirely through BWO // byte[] fast-path: size known upfront, write entirely through BWO
var argPayload = 1 + VarUIntSize((uint)byteArray.Length) + byteArray.Length; var argPayload = 1 + VarUIntSize((uint)byteArray.Length) + byteArray.Length;
bw.WriteRaw(argPayload); bw.WriteRaw(argPayload);
@ -414,6 +417,7 @@ public class AcBinaryHubProtocol : IHubProtocol
output.Advance(LengthPrefixSize); output.Advance(LengthPrefixSize);
var argBytes = AcBinarySerializer.Serialize(value, output, _options); var argBytes = AcBinarySerializer.Serialize(value, output, _options);
VerifyBwoAgainstArray(value, _options, argBytes);
Unsafe.WriteUnaligned(ref argLenSpan[0], argBytes); Unsafe.WriteUnaligned(ref argLenSpan[0], argBytes);
externalBytes += LengthPrefixSize + argBytes; externalBytes += LengthPrefixSize + argBytes;
@ -650,6 +654,72 @@ public class AcBinaryHubProtocol : IHubProtocol
#endregion #endregion
#region Diagnostics
[Conditional("DEBUG")]
private static void VerifyBwoAgainstArray(object? value, AcBinarySerializerOptions options, int bwoBytes)
{
if (DiagnosticLogger == null) return;
// Reference serialization via byte[] path
byte[] referenceBytes;
try
{
referenceBytes = AcBinarySerializer.Serialize(value, options);
}
catch (Exception ex)
{
DiagnosticLogger($"[VERIFY_WRITE] Array serialize FAILED for {value?.GetType().Name}: {ex.Message}");
return;
}
// BWO serialization to a temp ArrayBufferWriter to get comparable bytes
var tempWriter = new ArrayBufferWriter<byte>(Math.Max(Math.Max(referenceBytes.Length, bwoBytes) + 256, 4096));
var tempBytes = AcBinarySerializer.Serialize(value, tempWriter, options);
if (bwoBytes != referenceBytes.Length)
{
DiagnosticLogger($"[VERIFY_WRITE_MISMATCH] SIZE: Array={referenceBytes.Length}, BWO_pipe={bwoBytes}, BWO_temp={tempBytes} for {value?.GetType().Name}");
}
// Compare temp BWO output against Array reference byte-by-byte
var bwoSpan = tempWriter.WrittenSpan;
var refSpan = referenceBytes.AsSpan();
var minLen = Math.Min(bwoSpan.Length, refSpan.Length);
var mismatchCount = 0;
for (int i = 0; i < minLen; i++)
{
if (bwoSpan[i] != refSpan[i])
{
if (mismatchCount < 5) // log first 5 mismatches
{
var start = Math.Max(0, i - 8);
var end = Math.Min(minLen, i + 16);
var refHex = Convert.ToHexString(refSpan.Slice(start, end - start));
var bwoHex = Convert.ToHexString(bwoSpan.Slice(start, end - start));
DiagnosticLogger($"[VERIFY_WRITE_MISMATCH] CONTENT #{mismatchCount} at byte {i}/{minLen}: ref={refHex} bwo={bwoHex} type={value?.GetType().Name}");
}
mismatchCount++;
}
}
if (mismatchCount > 0)
{
DiagnosticLogger($"[VERIFY_WRITE_MISMATCH] Total {mismatchCount} differing bytes out of {minLen} compared (Array={referenceBytes.Length}, BWO_temp={tempBytes})");
return;
}
if (bwoSpan.Length != refSpan.Length)
{
DiagnosticLogger($"[VERIFY_WRITE_MISMATCH] Bytes match up to {minLen} but lengths differ: Array={referenceBytes.Length}, BWO_temp={tempBytes}");
return;
}
DiagnosticLogger($"[VERIFY_WRITE_OK] {referenceBytes.Length} bytes match for {value?.GetType().Name}");
}
#endregion
#region Helpers #region Helpers
private static InvocationMessage ApplyInvocationId(InvocationMessage msg, string? invocationId) private static InvocationMessage ApplyInvocationId(InvocationMessage msg, string? invocationId)

View File

@ -4,6 +4,7 @@ using AyCode.Core.Extensions;
using AyCode.Core.Helpers; using AyCode.Core.Helpers;
using AyCode.Core.Loggers; using AyCode.Core.Loggers;
using AyCode.Core.Serializers; using AyCode.Core.Serializers;
using AyCode.Core.Serializers.Binaries;
using AyCode.Interfaces.Entities; using AyCode.Interfaces.Entities;
using Microsoft.AspNetCore.Http.Connections; using Microsoft.AspNetCore.Http.Connections;
using Microsoft.AspNetCore.SignalR.Client; using Microsoft.AspNetCore.SignalR.Client;
@ -71,6 +72,7 @@ namespace AyCode.Services.SignalRs
{ {
hubBuilder.Services.AddSingleton<IHubProtocol, AyCodeBinaryHubProtocol>(); hubBuilder.Services.AddSingleton<IHubProtocol, AyCodeBinaryHubProtocol>();
AcBinaryHubProtocol.DiagnosticLogger = msg => Logger.Debug(msg); AcBinaryHubProtocol.DiagnosticLogger = msg => Logger.Debug(msg);
AcBinaryDeserializer.DiagnosticLogger = msg => Logger.Debug(msg);
} }
HubConnection = hubBuilder.Build(); HubConnection = hubBuilder.Build();