diff --git a/AyCode.Core/Loggers/AcLoggerBase.cs b/AyCode.Core/Loggers/AcLoggerBase.cs index 17f0dbe..406c7f3 100644 --- a/AyCode.Core/Loggers/AcLoggerBase.cs +++ b/AyCode.Core/Loggers/AcLoggerBase.cs @@ -27,6 +27,13 @@ public abstract class AcLoggerBase : IAcLoggerBase /// public bool ShortenCategoryNames { get; set; } = true; + /// + /// 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. + /// + 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; } + /// + /// 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 (<Method>d__N.MoveNext -> Method). + /// Only runs when the level is enabled and no EventId name was provided. + /// + 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 "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: "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"; + } + /// /// Maps Microsoft.Extensions.Logging.LogLevel to AyCode.Core.Loggers.LogLevel. /// diff --git a/AyCode.Core/docs/LOGGING/README.md b/AyCode.Core/docs/LOGGING/README.md index d782ca6..1430888 100644 --- a/AyCode.Core/docs/LOGGING/README.md +++ b/AyCode.Core/docs/LOGGING/README.md @@ -250,7 +250,7 @@ Colored console output. Thread-safe via `static readonly object ForWriterLock`. | Critical | Error | `Error("[CRITICAL] ...")` | | None | Disabled | — (ignored) | -`BeginScope` → no-op `NullScope` (scopes not supported). **ShortenCategoryNames** (default `true`): when MS logging passes fully-qualified type names (e.g. `Microsoft.AspNetCore.SignalR.HubConnectionHandler`), shortens to class name only (`HubConnectionHandler`). +`BeginScope` → no-op `NullScope` (scopes not supported). **ShortenCategoryNames** (default `true`): when MS logging passes fully-qualified type names (e.g. `Microsoft.AspNetCore.SignalR.HubConnectionHandler`), shortens to class name only (`HubConnectionHandler`). **ResolveBridgeCallerNames** (default `true`): bridge calls without an `EventId` name show the real caller resolved from the stack trace (see CallerMemberName Auto-Capture). ### ILoggerProvider @@ -284,7 +284,7 @@ Every named log method has a `*Conditional` counterpart (`InfoConditional`, `Err ### CallerMemberName Auto-Capture -Named log methods use `[CallerMemberName] string? memberName = null` — compiler auto-fills caller name. `ILogger.Log` (MS logging) uses `EventId.Name` if available, else `"Log"`. +Named log methods use `[CallerMemberName] string? memberName = null` — compiler auto-fills caller name. `ILogger.Log` (MS logging) uses `EventId.Name` if available, else resolves the real caller from the stack trace (logging-infrastructure frames skipped, async state machines / lambdas unwrapped to the source method). Opt-out: `ResolveBridgeCallerNames = false` → plain `"Log"` fallback. The stack walk costs a few µs and only runs for enabled bridge logs without an `EventId` name; named AC methods never pay it. ## Key Source Files diff --git a/AyCode.Services.Server/SignalRs/AcLoggerSignalRHub.cs b/AyCode.Services.Server/SignalRs/AcLoggerSignalRHub.cs index 792de80..f02af41 100644 --- a/AyCode.Services.Server/SignalRs/AcLoggerSignalRHub.cs +++ b/AyCode.Services.Server/SignalRs/AcLoggerSignalRHub.cs @@ -11,6 +11,20 @@ public class AcLoggerSignalRHub(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 diff --git a/AyCode.Services/Loggers/AcSignaRClientLogItemWriter.cs b/AyCode.Services/Loggers/AcSignaRClientLogItemWriter.cs index 8e87fa3..0c71a1e 100644 --- a/AyCode.Services/Loggers/AcSignaRClientLogItemWriter.cs +++ b/AyCode.Services/Loggers/AcSignaRClientLogItemWriter.cs @@ -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(); } + /// 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. 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); } - } - /// Hiba-állapotonként EGYSZER ír a Console.Error-ra (nem spamel) — a következő sikeres küldés élesíti újra. private void ReportFailureOnce(string message, Exception? ex) { + _connectedReported = false; // a következő sikeres felépülés újra jelentkezhessen + if (_failureReported) return; _failureReported = true; diff --git a/AyCode.Services/SignalRs/AcBinaryHubProtocol.cs b/AyCode.Services/SignalRs/AcBinaryHubProtocol.cs index 36b87bf..b33b112 100644 --- a/AyCode.Services/SignalRs/AcBinaryHubProtocol.cs +++ b/AyCode.Services/SignalRs/AcBinaryHubProtocol.cs @@ -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 r, IReadOnlyList paramTypes, object? headerContext)