Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at


  • matt-todd-rea 1 post 21 karma points
    Jan 08, 2024 @ 21:01
    matt-todd-rea
    0

    Serilog Stackoverflow exception

    Hi There, wondering if anyone has observed an issue like this, my Umbraco website V10.5.1, individual docker containers crash, randomly.

    Environment: AWS Server less Docker containers ASP.NET Core 6 RDS

    We have performed a migration from V7.15.3 and moved from VMs IIS hosting to AWS Server less Docker environment.

    We are using Serilog library for logging which is causing the application to regularly crash with a stack overflow, the log output that looks like this (in an endless loop - note that the first and last lines are the same):

       at Serilog.Core.Logger.Write(Serilog.Events.LogEvent)
       at Serilog.Extensions.Logging.SerilogLogger.Write[[Microsoft.Extensions.Logging.LoggerMessage+LogValues`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.Extensions.Logging.Abstractions, Version=7.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]](Serilog.Events.LogEventLevel, Microsoft.Extensions.Logging.EventId, LogValues`1<System.__Canon>, System.Exception, System.Func`3<LogValues`1<System.__Canon>,System.Exception,System.String>)
       at Serilog.Extensions.Logging.SerilogLogger.Log[[Microsoft.Extensions.Logging.LoggerMessage+LogValues`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.Extensions.Logging.Abstractions, Version=7.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, LogValues`1<System.__Canon>, System.Exception, System.Func`3<LogValues`1<System.__Canon>,System.Exception,System.String>)
       at Microsoft.Extensions.Logging.Logger`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].Microsoft.Extensions.Logging.ILogger.Log[[Microsoft.Extensions.Logging.LoggerMessage+LogValues`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], Microsoft.Extensions.Logging.Abstractions, Version=7.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60]](Microsoft.Extensions.Logging.LogLevel, Microsoft.Extensions.Logging.EventId, LogValues`1<System.__Canon>, System.Exception, System.Func`3<LogValues`1<System.__Canon>,System.Exception,System.String>)
       at Microsoft.Extensions.Logging.LoggerMessage+<>c__DisplayClass10_0`1[[System.__Canon, System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].<Define>g__Log|0(Microsoft.Extensions.Logging.ILogger, System.__Canon, System.Exception)
       at Microsoft.Extensions.Logging.LoggingExtensions.SessionCacheReadException(Microsoft.Extensions.Logging.ILogger, System.String, System.Exception)
       at Microsoft.AspNetCore.Session.DistributedSession.Load()
       at Microsoft.AspNetCore.Session.DistributedSession.get_Id()
       at Umbraco.Cms.Web.Common.AspNetCore.AspNetCoreSessionManager.get_SessionId()
       at Umbraco.Cms.Core.Logging.Serilog.Enrichers.HttpSessionIdEnricher.Enrich(Serilog.Events.LogEvent, Serilog.Core.ILogEventPropertyFactory)
       at Serilog.Context.LogContext.Enrich(Serilog.Events.LogEvent, Serilog.Core.ILogEventPropertyFactory)
       at Serilog.Context.LogContextEnricher.Enrich(Serilog.Events.LogEvent, Serilog.Core.ILogEventPropertyFactory)
       at Serilog.Core.Enrichers.SafeAggregateEnricher.Enrich(Serilog.Events.LogEvent, Serilog.Core.ILogEventPropertyFactory)
       at Serilog.Core.Logger.Dispatch(Serilog.Events.LogEvent)
       at Serilog.Core.Logger.Serilog.Core.ILogEventSink.Emit(Serilog.Events.LogEvent)
       at Serilog.Core.Logger.Dispatch(Serilog.Events.LogEvent)
       at Serilog.Core.Logger.Serilog.Core.ILogEventSink.Emit(Serilog.Events.LogEvent)
       at Serilog.Core.Logger.Dispatch(Serilog.Events.LogEvent)
       at Serilog.Core.Logger.Write(Serilog.Events.LogEvent)
    

    We do not have any consistent trigger that causes the website to crash, there is no apparent pattern to it even with very low traffic. We are observing container instances crashing once per hour.

    We believe that the HttpSessionIdEnricher function being called

      at Microsoft.AspNetCore.Session.DistributedSession.Load()
       at Microsoft.AspNetCore.Session.DistributedSession.get_Id()
    

    It appears that the Umbraco app is hard-coded to add the HttpSessionIdEnricher, the application startup flow as follows:

    1. Create an initial reloadable BootstrapLogger
    2. Start up the Umbraco application
    3. Umbraco adds the HttpSessionIdEnricher to the Serilog logger
    4. This enriched logger is then injected into the various Umbraco classes via dependency injection
    5. The Umbraco application starts up and is now running

    We have tried replacing the global Log.Logger object with an un-enriched logger after step 5, but by that point the Umbraco classes already have a logger with the enricher, so we still see the crash.

    This applies regardless of whether we replace the logger after calling services.AddUmbraco or whether we do it in a listener for an UmbracoApplicationStartedNotification event.

    I've tried reloading the configuration via the BootstrapLogger.Reload(...) method after step 5, but when dependency injection occurs the application will use the "current" configuration to create an immutable instance of the logger, so any Umbraco classes that have already been instantiated will use the enriched logger.

    I've tried replacing the Log.Logger before starting up the Umbraco application, but

    a) Umbraco will fail if you do not provide a reloadable logger, and b) if you do provide a reloadable logger then Umbraco will just add the enricher to it before using it for dependency injection. And steps 2-4 all occur within the Umbraco code, so it seems we can't replace the logger immediately after it's been enriched.

    If someone has seen this behavior before or could make some recommendations on how we might solve this would be greatly appreciated

  • Alexander 34 posts 84 karma points
    May 04, 2024 @ 20:40
    Alexander
    0

    I have the same problem but in azure and umbraco 13. Have you found the fix?

  • David van de Vliet 15 posts 116 karma points
    2 days ago
    David van de Vliet
    0

    Hi, I can also confirm this issue in Azure and Umbraco 13.

    We are using (also) distributed session storage and have a similar stack trace.

    I tried to replace Umbraco's AspNetCoreSessionManager with a custom one, but then still the exception happens when querying for the sessionId from the distributed session.

    I now think because of the logging level it tries to log the exception that happened querying for the sessionId, but then Umbraco's HttpSessionIdEnricher causes an endless recursive loop trying to enrich that event with the sessionId.

    I am still looking into this, but if anyone knows a fix for this already and would like to share it here, I would very much appreciate that.

    Regards, David

Please Sign in or register to post replies

Write your reply to:

Draft