0

I have a small ASP.NET Core 3.1 project that should execute the Odata request and then log either info or exception into the Loggly. I'm using Serilog for this.

But for some reason, it only sends the very first message from the Program.cs only (Log.Debug($"DEBUG: Starting at:{DateTime.Now}");), but does not send anything other than that. While it works fine for the Console or File logging. I have tried to fake an exception to trigger the Error logging. But nothing works (in the Loggly).

Any suggestions on why is that and how to make it work properly?

Here is my code:

Program.cs:

public class Program
{
    public static void Main(string[] args)
    {
        var configuration = new ConfigurationBuilder()
            .AddJsonFile("appsettings.json")
            .Build();

        Log.Logger = new LoggerConfiguration()
            .ReadFrom.Configuration(configuration)
            .CreateLogger();

        try
        {
            Log.Debug($"DEBUG: Starting at:{DateTime.Now}");
            CreateHostBuilder(args).Build().Run();
            Log.Debug($"DEBUG: Host created");
        }
        catch (Exception ex)
        {
            Log.Error("Oops something failed!");
            throw new Exception(ex.Message);
        }
        finally
        {
            Log.CloseAndFlush();
        }
    }

    public static IHostBuilder CreateHostBuilder(string[] args) =>
        Host.CreateDefaultBuilder(args)
            .ConfigureWebHostDefaults(webBuilder =>
            {
                webBuilder.UseStartup<Startup>();
            })
            .UseSerilog();
}

Startup.cs:

public class Startup
{
    public Startup(IConfiguration configuration)
    {
        Configuration = configuration;
    }

    public IConfiguration Configuration { get; }
    
    // This method gets called by the runtime. Use this method to add services to the container.
    public void ConfigureServices(IServiceCollection services)
    {
        services.AddControllers();
        services.AddDbContext<OdataTestObjectContext>(options =>
        {
            options.UseSqlServer(Configuration["ConnectionStrings:Database"]);
        });
        services.AddControllers().AddOData(opt =>
            opt.Filter().Expand().Select().OrderBy().Count().SetMaxTop(100)
                .AddRouteComponents("odata", GetEdmModel()));

        services.AddSwaggerGen(c =>
        {
            c.SwaggerDoc("v1", new OpenApiInfo { Title = "OdataTest", Version = "v1" });
            c.ResolveConflictingActions(apiDescriptions => apiDescriptions.First());
        });

        var appSettings = new ConfigurationBuilder().AddJsonFile("appsettings.json").Build(); 
        var serilogConfig = new LoggerConfiguration().ReadFrom.Configuration(appSettings);  
        services.AddLogging(loggingBuilder => loggingBuilder.AddSerilog(serilogConfig.CreateLogger(), true)); 

        services.AddMvc(opts => { opts.Filters.Add(new AutoLogAttribute()); });
    }

    // This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
    public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
    {

        if (env.IsDevelopment())
        {
            app.UseDeveloperExceptionPage();
            app.UseSwagger(c =>
            {
                c.RouteTemplate = "/swagger/{documentName}/swagger.json";
            });
            app.UseSwaggerUI(c => c.SwaggerEndpoint("/swagger/v1/swagger.json", "OdataTest v1"));
        }

        app.UseHttpsRedirection();
        ////Send "~/$odata" to debug routing if enable the following middleware
        app.UseODataRouteDebug();
        app.UseRouting();
        app.UseAuthorization();
        app.UseEndpoints(endpoints =>
        {
            endpoints.MapControllers();
        });
    }

    private static IEdmModel GetEdmModel()
    {
        var builder = new ODataConventionModelBuilder();
        var entitySet = builder.EntitySet<TestObject>("TestObjects");
        entitySet.EntityType.HasKey(entity => entity.Id);
        return builder.GetEdmModel();
    }
}

Controller.cs

[ApiController]
[Route("OData")]
public class TestController : ODataController
{
    private readonly OdataTestObjectContext _context;
    private readonly ILogger<TestController> _logger;

    public TestController(ILogger<TestController> logger, OdataTestObjectContext context)
    {
        _context = context;
        _logger = logger;
    }

    [ApiExplorerSettings(IgnoreApi = true)]
    [EnableQuery]
    public IActionResult Get()
    {
        try
        {
            return Ok(_context.TestObjects);
        }
        catch (Exception ex)
        {
            _logger.LogError("Error happened for Default query! - {0}", ex.Message);
            throw new InvalidOperationException(ex.Message);
        }
    }

    [HttpGet("Top({top})")]
    [EnableQuery]
    public IEnumerable<TestObject> GetTop(int top)
    {
        return _context.TestObjects.OrderByDescending(x => x.Id).Take(top);
    }

    [HttpGet("Enumerable")]
    [EnableQuery]
    public IEnumerable<TestObject> Enumerable()
    {         
        try
        {
            _logger.LogDebug("Executing ENUMERABLE now.");
            //string a = "asd";
            //int s = Convert.ToInt32(a);
            var results = _context.SaleInvoicesAndProducts.AsEnumerable();
            int z = 1;
            if (results.Any())
                z = 0;
            int i = 10 / z;
            return results;
        }
        catch (Exception ex)
        {
            _logger.LogError("Error happened for Enumerable query! - {0}", ex.Message);
            throw new Exception();
        }
    }

AutoLogAttribute.cs (this just outputs logs with some request's parameters):

   public class AutoLogAttribute : TypeFilterAttribute
    {
        public AutoLogAttribute() : base(typeof(AutoLogActionFilterImpl))
        {

        }

        private class AutoLogActionFilterImpl : IActionFilter
        {
            private readonly ILogger<AutoLogAttribute> _logger;
            public AutoLogActionFilterImpl(ILoggerFactory loggerFactory)
            {
                _logger = loggerFactory.CreateLogger<AutoLogAttribute>();
            }

            public void OnActionExecuting(ActionExecutingContext context)
            {
                // perform some business logic work
                _logger.LogInformation($"queryString: {context.HttpContext.Request.QueryString}");

                _logger.LogDebug($"queryString (Debug): {context.HttpContext.Request.QueryString}");
            }

            public void OnActionExecuted(ActionExecutedContext context)
            {
                //TODO: log body content and response as well
                _logger.LogInformation($"host: {context.HttpContext.Request.Host}");
                _logger.LogInformation($"patheAndQuery: {context.HttpContext.Request.GetEncodedPathAndQuery()}");

                _logger.LogDebug($"path (Debug): {context.HttpContext.Request.Path}");
                _logger.LogDebug($"host (Debug): {context.HttpContext.Request.Host}");
                _logger.LogDebug($"patheAndQuery (Debug): {context.HttpContext.Request.GetEncodedPathAndQuery()}");
            }
        }
    }

appsetting.json

    {
      "Serilog": {
        "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File", "Serilog.Sinks.Loggly" ],
        "MinimumLevel": {
          "Default": "Debug",
          "Override": {
            "Microsoft": "Debug",
            "System": "Debug"
          }
        },
        "Enrich": [ "FromLogContext", "WithMachineName", "WithProcessId", "WithThreadId" ],
        "WriteTo": [
          { "Name": "Console" },
          {
            "Name": "File",
            "Args": { "path": "C:\\ODATA\\log.json" }
          },
          {
            "Name": "Loggly",
            "Args": {
              "customerToken": "mytoken",
              "tags": "mytest"
            }
          }
        ],
    },
  "ConnectionStrings": {
    "Database": "Server=(localdb)\\MSSQLLocalDB;Initial Catalog=MyTestDB;Integrated Security=true;MultiSubnetFailover=True;MultipleActiveResultSets=True;"
  },
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  },
  "AllowedHosts": "*"
    
    }
KVN
  • 863
  • 1
  • 17
  • 35

1 Answers1

0

You can try to clear providers:

 Host
  ****
 .ConfigureLogging(logging =>
        {
            logging.ClearProviders();
        })
 .UseSerilog();

Also, if you have configured logging on Host, you don't need to put the additional configuration into Startup.cs

Serhii
  • 723
  • 1
  • 4
  • 12
  • Thanks. Unfortunately, it did not help. I have a suspicion that it might be because it never leaves the `CreateHostBuilder(args).Build().Run();` , but I'm not 100% sure and I'm not sure how to force it after each request execution. – KVN Feb 10 '22 at 00:16
  • So, you have logs only from Program.cs. Do you have other logs that show host start logs If no, then It looks like the configuration of host is wrong (configuration from appsetiings.json wasn't loaded properly) – Serhii Feb 10 '22 at 00:21
  • Then I would expect the File logging to not work either, is not it? But it works fine for file output (and in the location, I specified in the appsetting.json). – KVN Feb 10 '22 at 00:35
  • You can try to put bufferBaseFilename parameter and check if there is more logs available like described here: https://github.com/serilog/serilog-sinks-loggly – Serhii Feb 10 '22 at 00:42
  • Also, you can turn on Serilog SelfLog and find out if any errors occur: https://github.com/serilog/serilog/wiki/Debugging-and-Diagnostics – Serhii Feb 10 '22 at 00:56