SeriLog > Seq: Not always working on server?

[KeithBarrows]

When running in debug mode locally I have absolutely no complaints. However, I just rolled out 6 instances of the apps (Web APIs) and one API will write while the other does not. I don't have anything overly complex. I am also using LibLog to allow the consumed libraries to log on the initial logger.

How can I find out what is going on?

In the OWIN Startup I initialize my logger:

public class Startup
{
    public void Configuration(IAppBuilder app)
    {
        var appAssembly = typeof (Startup).Assembly;
        Aspect.Logging.LoggingHandler.Initialize(appAssembly);
        Log.Information("Starting WebApi...");

The Initialize looks like:

namespace BI.Aspect.Logging
{
    public static class LoggingHandler
    {
        public static void Initialize(System.Reflection.Assembly appAssembly)
        {
            var name = string.Empty;
            var version = string.Empty;
            if (appAssembly != null && !appAssembly.GetName().Name.Equals("System.Web"))
            {
                name = appAssembly.GetName().Name;
                version = appAssembly.GetName().Version.ToString();
            }

            Log.Logger = new LoggerConfiguration()
                .WriteTo.Seq(
                    ConfigSettingsWebApi.Instance.SeqUrl,
                    restrictedToMinimumLevel: ConfigSettingsWebApi.Instance.SeqEventLevelValue,
                    bufferBaseFilename: ConfigSettingsWebApi.Instance.SeqBufferPath)
                .WriteTo.RollingFile(
                    ConfigSettingsWebApi.Instance.LogFile,
                    restrictedToMinimumLevel: ConfigSettingsWebApi.Instance.LogFileEventLevelValue,
                    retainedFileCountLimit: ConfigSettingsWebApi.Instance.LogCount)
                .Enrich.With(new HttpRequestClientHostIPEnricher())
                .Enrich.With(new HttpRequestIdEnricher())
                .Enrich.With(new ThreadEnricher())
                .Enrich.WithProperty("Environment", string.Format("{0} [on {1}]", ConfigSettingsWebApi.Instance.EnvironmentName, Environment.MachineName))
                .Enrich.WithProperty("Application", name)
                .Enrich.WithProperty("App Version", version)
                .MinimumLevel.Verbose()
                .CreateLogger();

            Log.Information("---==< Logging Started >==---");
            Log.Debug("Environment: {val}, App: {app}, Ver: {ver}, Logging to file: {fileName}, Level: {@logLevel}, Logging to SEQ: {fileName}, Level: {@logLevel}"
                , ConfigSettingsWebApi.Instance.EnvironmentName
                , name
                , version
                , ConfigSettingsWebApi.Instance.LogFile
                , ConfigSettingsWebApi.Instance.LogFileEventLevelValue
                , ConfigSettingsWebApi.Instance.SeqUrl
                , ConfigSettingsWebApi.Instance.SeqEventLevelValue);
        }
    }
}

I have a [Log] attribute on each controller at the class level to capture the entrance and exit of each Controller/Action. On Web API 1, works like a charm. On Web API 2, nothing gets to Seq but the rolling file is populated. That code looks like:

namespace BI.Security.Library.Attributes
{
    public class LogAttribute : ActionFilterAttribute
    {
        public override void OnActionExecuting(HttpActionContext actionContext)
        {
            var actionName = actionContext.ActionDescriptor.ActionName;
            var controllerName = actionContext.ControllerContext.ControllerDescriptor.ControllerName;
            Log.Information("Entered [{controller:l}.{action:l}]", controllerName, actionName);

            var request = actionContext.Request;
            Log.Information("{@method} {@uri} {@headers}", request.Method, request.RequestUri, request.Headers);
            actionContext.ActionArguments.ToList()
                .ForEach(kvp => Log.Verbose("ActionArguments: Key = {key}, Value = {@value}", kvp.Key, kvp.Value));
        }

        public override void OnActionExecuted(HttpActionExecutedContext actionExecutedContext)
        {
            var actionName = actionExecutedContext.ActionContext.ActionDescriptor.ActionName;
            var controllerName = actionExecutedContext.ActionContext.ControllerContext.ControllerDescriptor.ControllerName;

            if (actionExecutedContext.ActionContext.Response != null && actionExecutedContext.ActionContext.Response.Content != null)
            {
                var objectContent = (ObjectContent) actionExecutedContext.ActionContext.Response.Content;
                Log.Information("Body returned - type: {@objectType}", objectContent.ObjectType);
                Log.Verbose("Body returned - value: {@objectType}", objectContent.Value);
            }
            if (actionExecutedContext.Exception != null)
            {
                Log.Warning("[{controller:l}.{action:l}] threw an unhandled exception!", controllerName, actionName);
            }
            Log.Information("Exited [{controller:l}.{action:l}]", controllerName, actionName);
        }
    }
}

Thoughts?

[nblumhardt]

Hi Keith,

It's possible you're hitting the payload size limit on the Seq server; you can check this by increasing the value in Settings > System > Raw event payload limit. (Note that after changing this value you may need to wait a little while for the app to retry, unless you can restart the app.)

If this doesn't do the trick, is there any way you can collect output from SelfLog?

Regards,
Nick

[KeithBarrows]

I can add SelfLog. Will also mean rolling out upgrades to all environments. That way we can web.config control if SelfLog is being used or not. Hopefully today (late) I can get that rolled out.

Looking at the memory it appears it should be ok. 1MB should cover us. Also, the 134MB Free HD space should be adequate. We are not pounding Seq that hard (yet).

[nblumhardt]

Regarding the 1 MB, it can be quite surprising how big some serialized log messages can get; I think 1 MB was a bit low for the default in Seq, so it will be 10 MB in Seq 3.0 when that is ready.

Did you end up with any more information out of SelfLog? Cheers!

[KeithBarrows]

I finally got logging turned on, found a problem talking to the Seq server. Got the ports punched open (took 2 tries for IT to do it right) and things started flowing.

10MB? Hmm. OK, I can see that but right now we do not have anything except exceptions that are bigger than 100KB! Our first consumer of our new APIs are mobile clients so we targeted small.

Still tracking down a few moving pieces that don't seem to be logging and nothing is dropping into Serilog's selflog yet either...

[nblumhardt]

Great, thanks for the follow-up. Let us know how you go! :-)

[nblumhardt]

Hi Keith - any update here? Assuming all is good - let me know if you're still seeing any issues and we'll reopen.

[KeithBarrows]

Found several problems with the use of the debug log. Chief amongst them
was the ports not being open in the right direction and the load balancer
not looking for the Seq port.

Thanks!

[image: --]
Keith Barrows
[image: https://]about.me/kbarrows
https://about.me/kbarrows?promo=email_sig

On Thu, Feb 11, 2016 at 2:47 PM, Nicholas Blumhardt <
notifications@github.com> wrote:

Closed #625 #625.

—
Reply to this email directly or view it on GitHub
#625 (comment).

[nblumhardt]

Thanks Keith 👍