Gerando logs em JSON com log4net

code

Recentemente, minha equipe ficou a cargo de um sistema legado escrito em .NET Framework. Um dos grandes problema deste legado, é que não tínhamos nenhuma visibilidade do que ocorria no sistema.

Uma das formas de resolver este problema, era enviar logs do sistema ao Kibana (plugin de visualização de dados para o Elasticsearch), que foi a opção que escolhemos.

Enviar logs no formato “standard” ao Kibana, complicava a criação de gráficos mais complexos no Grafana (aplicação web com visualização interativa de tabelas, gráficos e alertas). Daí surgiu a necessidade de gerar logs no formato JSON.

Para gerar logs no formato JSON, necessitamos criar um novo layout e formatar o saída no formato desejado.

Nossa classe terá o nome de JsonLayout e deve extender LayoutSkeleton (do namespace log4net.Layout). A classe LayoutSkeleton implementa duas interfaces (ILayout e IOptionHandler), por isso devemos implementar os métodos: ActivateOptions e Format.

public class JsonLayout : LayoutSkeleton
{
public override void ActivateOptions()
{
}
public override void Format(TextWriter writer, LoggingEvent e)
{
}
}
view raw JsonLayout_ hosted with ❤ by GitHub

Já temos a nossa classe criada, necessitamos implementar nossa formatação customizada no método Format.

Nesse exemplo, vamos imprimir no log os campos:

  • messageObject (que passamos como parámetro ao logear)
  • requestId
  • pid
  • timestamp
  • level
  • logger
  • location
  • thread
  • exceptionObject (exception que passamos como parámetro ao logear um erro)
  • exceptionObjectString

Assim ficou a nossa classe:

public class JsonLayout : LayoutSkeleton
{
public override void ActivateOptions()
{
}
public override void Format(TextWriter writer, LoggingEvent e)
{
var log = new
{
messageObject = e.MessageObject,
requestId = Guid.NewGuid().ToString(),
pid = Process.GetCurrentProcess().Id,
timestamp = e.TimeStamp.ToUniversalTime().ToString("O"),
level = e.Level.DisplayName,
logger = e.LoggerName,
location = e.LocationInformation.ClassName,
thread = e.ThreadName,
exceptionObject = e.ExceptionObject,
exceptionObjectString = e.ExceptionObject == null ? null : e.GetExceptionString()
};
writer.WriteLine(JsonConvert.SerializeObject(log));
}
}
view raw JsonLayout hosted with ❤ by GitHub

Agora só falta referenciar nossa classe JsonLayout no arquivo log4net.config:

<configuration>
  <log4net>
    <appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender,log4net">
      ...
      <layout type="MyNamespace.JsonLayout">
      </layout>
    </appender>
    ...
  </log4net>
</configuration>

Escrevemos um log na nossa aplicação:

internal static class Program
{
private static readonly ILog Logger = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
public static void Main(string[] args)
{
var logObject = new
{
message = "new log message",
field = "some data"
};
Logger.Info(logObject);
}
}
view raw Program_Log.cs hosted with ❤ by GitHub

E voilà:

{
  "messageObject": {
    "message": "new log message",
    "field": "some data"
  },
  "requestId": "9e20b1b3-9064-4ebf-9d84-6662c7673324",
  "pid": 25829,
  "timestamp": "2020-12-17T00:16:15.0696380Z",
  "level": "INFO",
  "logger": "Log4netOutputJson.Program",
  "location": "Log4netOutputJson.Program",
  "thread": "1",
  "exceptionObject": null,
  "exceptionObjectString": null
}

O projeto de exemplo está hospedado no GitHub: https://github.com/victorlss/log4net-output-json

Audit Trail com Entity Framework Core

Uma Trilha de Auditoria (também chamada de Log de Auditoria) é uma das maneiras mais eficazes de rastrear as ações dos usuários, fornecendo evidências de uma sequência de atividades que afetam informações, processos etc.

Usando o Entity Framework Core, podemos facilmente auditar as alterações, sobrescrevendo o método SaveChanges ().

Vamos ao que interessa

Defina a classe context e as classes de entidade que conformam seu modelo:

public class BloggingContext : DbContext
{
protected override void OnConfiguring
(DbContextOptionsBuilder optionsBuilder)
{
optionsBuilder.UseSqlServer(
"Server=localhost;Database=Blogging;User Id=sa;
Password=<YourStrong!Passw0rd>");
}
public DbSet<Blog> Blogs { get; set; }
public DbSet<Post> Posts { get; set; }
}
view raw BloggingContext.cs hosted with ❤ by GitHub
public class Blog
{
public int BlogId { get; set; }
public string Url { get; set; }
public ICollection<Post> Posts { get; set; }
}
public class Post
{
public int PostId { get; set; }
public string Title { get; set; }
public string Content { get; set; }
public int BlogId { get; set; }
public Blog Blog { get; set; }
}
view raw Models.cs hosted with ❤ by GitHub

Agora, devemos definir uma classe context auditável e o modelo AuditTrail:

public class BloggingAuditableContext : BloggingContext
{
public override int SaveChanges()
{
ChangeTracker.Entries().Where(p => p.State == EntityState.Modified).ToList().ForEach(entry =>
{
Audit(entry);
});
return base.SaveChanges();
}
private void Audit(EntityEntry entry)
{
foreach (var property in entry.Properties)
{
if (!property.IsModified)
continue;
var auditEntry = new AuditTrail
{
Table = entry.Entity.GetType().Name,
Column = property.Metadata.Name,
OldValue = property.OriginalValue.ToString(),
NewValue = property.CurrentValue.ToString(),
Date = DateTime.Now
};
this.AuditTrail.Add(auditEntry);
}
}
}
view raw BloggingAuditContext.cs hosted with ❤ by GitHub
public class BloggingContext : DbContext
{
...
public DbSet<AuditTrail> AuditTrail { get; set; }
}
view raw BloggingContext.cs hosted with ❤ by GitHub
...
public class AuditTrail
{
public long AuditTrailId { get; set; }
public string Table { get; set; }
public string Column { get; set; }
public string OldValue { get; set; }
public string NewValue { get; set; }
public DateTime Date { get; set; }
}
view raw Models.cs hosted with ❤ by GitHub

Com os comandos de migração EF, criamos nossa base de dados e suas tabelas:

dotnet ef migrations add InitialCreate --context BloggingContext
dotnet ef database update --context BloggingContext

Vamos aos testes

Adicionaremos dados a nossa tabela Blog:

INSERT INTO [Blogging].[dbo].[Blogs] (Url) 
VALUES ('blog.victorleonardo.com');

Agora, devemos efetuar uma atualização ao registro que acabamos de inserir, utilizando nossa classe context auditável:

...
using (var auditableContext = new BloggingAuditableContext())
{
var blog = auditableContext.Blogs.FirstOrDefault();
blog.Url = "test.victorleonardo.com";
auditableContext.SaveChanges();
}
...
view raw BloggingAuditTest.cs hosted with ❤ by GitHub

Voilà:

This image has an empty alt attribute; its file name is Screen-Shot-2019-04-28-at-4.41.21-PM.png