Improve logger caller resolution and SignalR log reporting

Added ResolveBridgeCallerNames to AcLoggerBase for accurate caller detection in ILogger bridge logs using stack trace analysis. Updated debug logging to include caller info via EventId. Enhanced AcLoggerSignalRHub and AcSignaRClientLogItemWriter to log connection lifecycle events and improve connection state reporting. Updated documentation to reflect these changes.
This commit is contained in:
Loretta 2026-07-12 19:41:11 +02:00
parent b210517826
commit f2c636bb1c
5 changed files with 99 additions and 22 deletions

View File

@ -27,6 +27,13 @@ public abstract class AcLoggerBase : IAcLoggerBase
/// </summary>
public bool ShortenCategoryNames { get; set; } = true;
/// <summary>
/// If true, ILogger bridge calls without an EventId name resolve the real caller from the stack trace
/// (async state machines unwrapped) instead of showing "Log". Costs a few µs per enabled bridge log;
/// named AC methods (Debug/Info/...) are unaffected. Set false to restore the plain "Log" fallback.
/// </summary>
public bool ResolveBridgeCallerNames { get; set; } = true;
protected AcLoggerBase() : this(null)
{
}
@ -207,8 +214,11 @@ public abstract class AcLoggerBase : IAcLoggerBase
var fullMessage = message;
var category = ShortenCategoryNames ? GetShortCategoryName(CategoryName) : CategoryName;
// Use eventId.Name as memberName if available, otherwise null (will show as empty, not "Log")
var memberName = !string.IsNullOrEmpty(eventId.Name) ? $"{eventId.Name}:{eventId.Id}" : "Log";
// Explicit EventId name wins; otherwise resolve the real caller from the stack (opt-out: ResolveBridgeCallerNames).
// EventId.Id 0 means "no id" — show the bare name without the ":0" suffix.
var memberName = !string.IsNullOrEmpty(eventId.Name)
? eventId.Id != 0 ? $"{eventId.Name}:{eventId.Id}" : eventId.Name
: ResolveBridgeCallerNames ? ResolveCallerFromStackTrace() : "Log";
switch (logLevel)
{
@ -249,6 +259,48 @@ public abstract class AcLoggerBase : IAcLoggerBase
return lastDot >= 0 ? categoryName[(lastDot + 1)..] : categoryName;
}
/// <summary>
/// Finds the first stack frame outside the logging infrastructure so ILogger bridge calls
/// (LogDebug/LogInformation/... extensions — these cannot carry CallerMemberName) still show
/// the real caller. Async state machines and lambdas are unwrapped (&lt;Method&gt;d__N.MoveNext -> Method).
/// Only runs when the level is enabled and no EventId name was provided.
/// </summary>
private static string ResolveCallerFromStackTrace()
{
var stackTrace = new StackTrace(skipFrames: 1, fNeedFileInfo: false);
var frameCount = Math.Min(stackTrace.FrameCount, 15);
for (var i = 0; i < frameCount; i++)
{
var method = stackTrace.GetFrame(i)?.GetMethod();
var declaringType = method?.DeclaringType;
if (method == null || declaringType == null) continue;
if (declaringType.Namespace?.StartsWith("Microsoft.Extensions.Logging", StringComparison.Ordinal) == true) continue;
if (typeof(AcLoggerBase).IsAssignableFrom(declaringType)) continue;
// Async state machine: compiler-generated "<Method>d__N" type, method is MoveNext.
var typeName = declaringType.Name;
if (typeName.Length > 2 && typeName[0] == '<')
{
var end = typeName.IndexOf('>');
if (end > 1) return typeName[1..end];
}
// Lambda / local function: "<Caller>b__0"-style method name — unwrap to the containing method.
var methodName = method.Name;
if (methodName.Length > 2 && methodName[0] == '<')
{
var end = methodName.IndexOf('>');
if (end > 1) return methodName[1..end];
}
return methodName;
}
return "Log";
}
/// <summary>
/// Maps Microsoft.Extensions.Logging.LogLevel to AyCode.Core.Loggers.LogLevel.
/// </summary>

File diff suppressed because one or more lines are too long

View File

@ -11,6 +11,20 @@ public class AcLoggerSignalRHub<TLogger>(TLogger logger) : Hub where TLogger : I
{
private TLogger _logger = logger;
// Kapcsolat-életciklus markerek: enélkül a szerver-konzolból nem látszik, hogy a kliens-log csatorna
// egyáltalán felépült-e (a néma loggerHub a "sosem csatlakozott" és a "csatlakozott, de nem küld" esetben ugyanúgy néz ki).
public override async Task OnConnectedAsync()
{
_logger.Info($"Logger client connected; ConnectionId: {Context.ConnectionId}");
await base.OnConnectedAsync();
}
public override async Task OnDisconnectedAsync(Exception? exception)
{
_logger.Info($"Logger client disconnected; ConnectionId: {Context.ConnectionId}{(exception == null ? string.Empty : $"; ex: {exception.GetType().Name}: {exception.Message}")}");
await base.OnDisconnectedAsync(exception);
}
public void AddLogItem(AcLogItem? logItem)
{
try

View File

@ -16,6 +16,7 @@ namespace AyCode.Services.Loggers
// Spam-védelem: hiba-állapotonként EGY jelentés; sikeres küldés után a kapu újraélesedik, és
// helyreálláskor kiírjuk, hány log-item veszett el. (Egyszerű mezők — a torz dupla-jelentés ártalmatlan.)
private bool _failureReported;
private bool _connectedReported;
private long _droppedCount;
public AcSignaRClientLogItemWriter(string fullHubName, AppType appType = AppType.Web, LogLevel logLevel = LogLevel.Detail, string? categoryName = null) : base(appType, logLevel, categoryName)
@ -28,17 +29,33 @@ namespace AyCode.Services.Loggers
//.AddMessagePackProtocol(options => options.SerializerOptions = MessagePackSerializerOptions.Standard.WithSecurity(MessagePackSecurity.UntrustedData))
.Build();
// A .Forget() logger nélkül elnyelné az induló kapcsolat hibáját → jelentő wrapper.
StartConnectionReportedAsync().Forget();
StartConnection().Forget();
}
/// <summary>NEM dob: a kapcsolódási hibát maga jelenti (ReportFailureOnce) — a hívók (ctor fire-and-forget,
/// WriteLogItemCallback) a State-ből látják az eredményt.</summary>
public async Task StartConnection()
{
if (_hubConnection.State == HubConnectionState.Disconnected)
await _hubConnection.StartAsync();
try
{
if (_hubConnection.State == HubConnectionState.Disconnected)
await _hubConnection.StartAsync();
if (_hubConnection.State != HubConnectionState.Connected)
await TaskHelper.WaitToAsync(() => _hubConnection.State == HubConnectionState.Connected, 10000, 10, 25);
if (_hubConnection.State != HubConnectionState.Connected)
await TaskHelper.WaitToAsync(() => _hubConnection.State == HubConnectionState.Connected, 10000, 10, 25);
// Felépülés-marker (kapcsolatonként egyszer) — enélkül a „minden csendben OK" és a „soha el sem indult"
// megkülönböztethetetlen a konzolból.
if (_hubConnection.State == HubConnectionState.Connected && !_connectedReported)
{
_connectedReported = true;
Console.WriteLine($"[{nameof(AcSignaRClientLogItemWriter)}] connected; url: {_fullHubName}");
}
}
catch (Exception ex)
{
ReportFailureOnce("connect failed", ex);
}
}
public async Task StopConnection()
@ -79,15 +96,11 @@ namespace AyCode.Services.Loggers
}
}
private async Task StartConnectionReportedAsync()
{
try { await StartConnection(); }
catch (Exception ex) { ReportFailureOnce("initial connect failed", ex); }
}
/// <summary>Hiba-állapotonként EGYSZER ír a Console.Error-ra (nem spamel) — a következő sikeres küldés élesíti újra.</summary>
private void ReportFailureOnce(string message, Exception? ex)
{
_connectedReported = false; // a következő sikeres felépülés újra jelentkezhessen
if (_failureReported) return;
_failureReported = true;

View File

@ -1383,7 +1383,7 @@ public class AcBinaryHubProtocol : IHubProtocol
}
[Conditional("DEBUG")]
protected void DebugLogArgument(Type runtimeType, int argBytes, object? value)
protected void DebugLogArgument(Type runtimeType, int argBytes, object? value, [CallerMemberName] string? caller = null)
{
var kind = value switch
{
@ -1393,15 +1393,13 @@ public class AcBinaryHubProtocol : IHubProtocol
_ => "scalar"
};
_logger?.LogDebug("WriteArgument runtimeType={RuntimeType} argBytes={ArgBytes} valueIsNull={ValueIsNull} valueTypeKind={Kind}", runtimeType.FullName, argBytes, value == null, kind);
Console.WriteLine($"[DEBUG] WriteArgument runtimeType={runtimeType.FullName} argBytes={argBytes} valueIsNull={value == null} kind={kind}");
_logger?.LogDebug(new EventId(0, caller), "WriteArgument runtimeType={RuntimeType} argBytes={ArgBytes} valueIsNull={ValueIsNull} valueTypeKind={Kind}", runtimeType.FullName, argBytes, value == null, kind);
}
[Conditional("DEBUG")]
protected void DebugLogArgument(Type targetType, int argLength, long remaining)
protected void DebugLogArgument(Type targetType, int argLength, long remaining, [CallerMemberName] string? caller = null)
{
_logger?.LogDebug("ReadSingleArgument targetType={TargetType} argLength={ArgLength} remaining={Remaining}", targetType.FullName, argLength, remaining);
Console.WriteLine($"[DEBUG] ReadSingleArgument targetType={targetType.FullName} argLength={argLength} remaining={remaining}");
_logger?.LogDebug(new EventId(0, caller), "ReadSingleArgument targetType={TargetType} argLength={ArgLength} remaining={Remaining}", targetType.FullName, argLength, remaining);
}
private object?[] ReadArguments(ref SequenceReader<byte> r, IReadOnlyList<Type> paramTypes, object? headerContext)