ILogger ile MS SQL’e Asenkron Loglama
Ekibimizin sorumluluğu gereği, çok sık olmasa da yurt dışı partnerlerimize ihtiyaçları doğrultusunda yazılımlar geliştirdiğimiz oluyor. Bu yazılımlar çoğu zaman, DeFacto’da alt yapı ekibimiz tarafından geliştirilmiş ve geçtiğimiz yaz CNCF’de case study’si yayınlanmış DfApi platformunda geliştiriliyor (Case Study için buraya — DeFacto | CNCF). Ancak nadiren de olsa bu yazıyı yazmama vesile olan; sınırlamalardan ötürü DfApi kullanmadan, belirli limitlere uymak koşulu ile nasıl yazacağımızda özgür olduğumuz şekilde de geliştiriliyor.
Birkaç ay önce bu şekilde bir talep geldi. Gerekli toplantıları yaptıktan sonra büyüklüğü neticesinde proje kapsamına aldık. Proje iki koldan oluşuyor; mobil ve backend. Proje tamamlandıktan sonra partnere teslim edilecek ve uygulamanın tüm devOps süreçleri partnerimizin sorumluluğunda olacak. Bu sebeple uygulamanın güncel bir Asp.NET sürümü ile yazılmasını, MS SQL kullanılmasını ve bunların haricinde çok da gerekli olmadıkça farklı teknolojiler kullanma anlamında uçup kaçılmamasını talep ettiler 😊 Backend projemiz tamamı ile mobil tarafa hizmet edecek. Dolayısı ile response sürelerimiz bizim için çok önemli. Ayrıca projenin maliyeti açısından gerekirse on kere analiz edelim ama bir kere yazalım düşüncesi ile ilerledik. Bu iki sebep yüzünden de gereksiz hiç bir kod yazmamaya özen gösterdik.
Buraya kadar nasıl bir senaryo ile karşı karşıya olduğumuzu anlatmaya çalıştım. Başlıktan da anlayacağınız üzere bu yazıda; ILogger ile database üzerine asenkron bir şekilde, response süresine neredeyse hiç bir etkisi olmadan nasıl loglama yaptığımızdan bahsedeceğim.
Kısaca…
Nispeten uzun bir yazı olacağından önce yapıyı özetlemekte fayda görüyorum. Önceki yazılarımda denk geldiysek ‘.NET de varsa dışarıda arama’ kafasında biri olduğumu biliyorsunuzdur 😊 Hem bu hem de projenin sınırlamalarından dolayı ILogger interface’inden faydalandık. Bunu için; öncelikle ILoggerProvider interface’ini kullanarak DatabaseLoggerProvider oluşturacağız. Bu provider bize proje içerisinde ILogger kullanacağımız yerlerde yazdığımız DatabaseLogger’ı sağlayacak. Daha sonra provider’ı Program.cs içerisinde ILoggingBuilder’ın service collection’ına ekleyeceğiz. Ekleyeceğiz ki; biz ILogger istediğimizde DatabaseLoggerProvider bize DatabaseLogger sınıfının gerekli ayarlamalarını yapıp hizmetimize sunsun.
Buraya kadar ki kısım aslında yazdığımız custom database logger içerisinde ILogger interface’inden gelen Log methoduna gitmemizi ve oradan database bağlantısı ile log kaydı atmamıza olanak veriyor. Ancak kullanıcıdan gelen isteğin loglama için database’e yazması esnasında bekletilmesini istemiyoruz çünkü neredeyse her istek ve business’da derinlere girdikçe işlemler detaylı bir şekilde loglanıyor. Bu sebeptendir ki ConcurrentQueue oluşturup logları önce kuyruğa yazıp daha sonra bir BackgroundService yardımı ile kuyruktakileri database’e aktarıyoruz. Bu sayede request’den response’a kadar geçen sürede loglama süre maliyetini sadece kuyruğa item ekleme kadar düşüğe çekmiş oluyoruz.
Bu yapının bize avantajları da var dezavantajları da buna yazının sonunda değineceğim.
DbLoggerProvider ve DbLogger’ın oluşturulması
Microsoft.Extensions.Logging namespace’i altında bulunan ILoggerProvider; bize ILogger interface’inden türemiş bir tipi loglama için kullanabilmemizi sağlıyor. Yani biz Asp.NET’e diyoruz ki; “al bu ILoggerProvider’dan türetilmiş DbLoggerProvider class’ını WebApplicationBuilder altındaki Logging’in servis koleksiyonuna ekle. Uygulama ayağa kalkarken Provider’ın gösterdiği şekilde ILogger’dan türemiş DbLogger sınıfını oluştur. İhtiyacımız olduğunda constructor injection ile isteyeceğiz ve log methodunu kullanacağız. O aşamada bize verirsin.“
// Program.cs
builder.Logging.ClearProviders();
builder.Logging.AddDbLogger(configuration =>
{
configuration.IsActive = builder.Configuration.GetValue<bool>("Logging:DatabaseLogging:IsActive");
configuration.DbConnectionStr = builder.Configuration.GetValue<string>("Logging:DatabaseLogging:RUBLMobilDevLoggingDatabase");
});Yukarıda log service collection’a provider’ımızı eklememize yardımcı olan AddDbLogger merhod’u aslında bir extension method.
// DbLoggerExtension
public static ILoggingBuilder AddDbLogger(this ILoggingBuilder builder, Action<DbLoggerConfiguration> configure)
{
builder.AddConfiguration();
LoggerProviderOptions.RegisterProviderOptions<DbLoggerConfiguration, DbLoggerProvider>(builder.Services);
builder.Services.Configure(configure);
builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<ILoggerProvider, DbLoggerProvider>());
return builder;
}Extension Method içerisini açıklamak gerekirse;
- AddConfiguration methodu; LoggerProviderFactory üzerinden eklenen LoggerProvider’lara (yani bizim yaptığımız gibi custom logger’lar için) AppSettings içerisindeki loglama tercihlerine erişimi sağlıyor.
- TryAddEnumerable ile singleton olarak DbLoggerProvider’ı ekliyoruz. Aslında bu satır sayesinde yazdığımız database logger’dan sistemi haberdar etmiş oluyoruz.
- RegisterProviderOption method’u; DbLoggerProvider ile DbLoggerConfiguration’ı ilişiğini sağlıyor. Yani DbLoggerProvider ile eklenen database logger’lar DbLoggerConfiguration dosyası ile beslenecek diyor. Tabii bu method configuration dosyasını da AddConfiguration methodu (ilk satır) sayesinde alıyor.
- Configure methodu ile configuration’ı, AppSetting içerisinde ekstradan eklediğimiz ayarlardan (IsActive, TMDatabase…) haberdar ediyoruz.
[ProviderAlias("DatabaseLogging")]
public class DbLoggerProvider : ILoggerProvider
{
private readonly IDisposable? _onChangeToken;
private readonly DbLoggerService _dbLoggerService;
private DbLoggerConfiguration _currentConfig;
private readonly ConcurrentDictionary<string, DbLogger> _loggers = new(StringComparer.OrdinalIgnoreCase);
public DbLoggerProvider(IOptionsMonitor<DbLoggerConfiguration> config, DbLoggerService dbLoggerService)
{
_currentConfig = config.CurrentValue;
_onChangeToken = config.OnChange(updatedConfig => _currentConfig = updatedConfig);
_dbLoggerService = dbLoggerService;
}
public ILogger CreateLogger(string categoryName)
=> _loggers.GetOrAdd(categoryName, name => new DbLogger(name, GetCurrentConfig, _dbLoggerService));
private DbLoggerConfiguration GetCurrentConfig() => _currentConfig;
public void Dispose()
{
_loggers.Clear();
_onChangeToken?.Dispose();
}
}DbLoggerProvider içerisindeki CreateLogger methodu yazdığımız (aşağıdaki kod bloğu) database logger’ı dönüyoruz. Artık ILogger ile logger istediğimiz yerlerde sistem bize DbLoggerProvider ile tanımladığımız DbLogger’ı verecek.
Buraya kadar sisteme yazdığımız database logger’ı eklemek ile uğraştık. Aşağıda da loglarımızı log kuyruğuna ekleyecek DbLogger’ımız var.
public sealed class DbLogger : ILogger
{
private readonly string _name;
private readonly Func<DbLoggerConfiguration> _getCurrentConfig;
private readonly DbLoggerService _loggerService;
public DbLogger(string name, Func<DbLoggerConfiguration> getCurrentConfig, DbLoggerService loggerService)
{
_name = name;
_getCurrentConfig = getCurrentConfig;
_loggerService = loggerService;
}
public IDisposable? BeginScope<TState>(TState state) where TState : notnull
=> default!;
public bool IsEnabled(LogLevel logLevel)
{
return _getCurrentConfig().IsActive && !string.IsNullOrEmpty(_getCurrentConfig().DbConnectionStr);
}
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
if (!IsEnabled(logLevel))
return;
var log = new Log()
{
EventId = eventId.Id,
LogLevel = logLevel.ToString(),
ShortCode = _name,
Message = formatter(state, exception),
ExceptionMessage = exception?.Message ?? null,
ExceptionStackTrace = exception?.StackTrace ?? null,
LogTime = DateTime.UtcNow
};
_loggerService.Log(log);
}
}DbLogger class’ında Log methodu ile DbLoggerService içerisindeki Log method’unu kullanarak ConcurrentQueue’ya logumuzu ekliyoruz.
Bu yapıyı kurarken içime sinen işlerden biri de IOptionsMonitor yardımı ile uygulama ayakta ve istekler almaya devam ederken loglama üzerinde ayar değişikliği (logLevel, loglamayı kapatıp açmak vb.) yapabiliyor olmamız oldu. Sağladığı OnChange methodu sayesinde değişikliği dinleyip güncel config’i okuyabileceğimiz bir action verebiliyoruz.
Buraya kadar loglarımızı kuyruğa ekledik. Şimdi sıra kuyruktakileri bir BackgroundService ile database’e yazmakta.
DbLoggerService ve LogBackgroundService’in oluşturulması
DbLoggerService bizim log kuyruğumuzu tutan ve ILogger ile BackgroundService arasında köprü vazifesi taşıyan bir class. Köprü vazifesinden kastım şu; ILogger’ın Log methodu’u logu kuyruğa yazıyor ve BackgroudService de bu kuyruktan okuyup database’e yazıyor.
public class DbLoggerService
{
private readonly ConcurrentQueue<Log> _logsQueue = new();
private readonly IConfiguration _configuration;
public DbLoggerService(IConfiguration configuration)
{
_configuration = configuration;
}
public async Task WriteLogsToDatabase(CancellationToken cancellationToken)
{
if (_logsQueue.IsEmpty)
return;
Log? log = null;
try
{
var optionsBuilder = new DbContextOptionsBuilder<AppDbContext>();
optionsBuilder.UseSqlServer(_configuration.GetValue<string>("Logging:DatabaseLogging:TMDatabase"));
using var dbContext = new AppDbContext(optionsBuilder.Options);
while (!_logsQueue.IsEmpty && !cancellationToken.IsCancellationRequested)
{
bool didDequeue = _logsQueue.TryDequeue(out log);
if (didDequeue)
await dbContext.Logs.AddAsync(log!, cancellationToken);
}
await dbContext.SaveChangesAsync(cancellationToken);
}
catch (Exception ex)
{
if (log != null)
_logsQueue.Enqueue(log);
Console.WriteLine(ex.ToString());
}
}
public void Log(Log log)
{
_logsQueue.Enqueue(log);
}
}WriteLogsToDatabase(…) : Backgroud service tarafından çağırılan method.
Log(…) : ILogger’ın Log methodu tarafından çağırılan method.
public class LogBackgroudService : BackgroundService
{
private readonly DbLoggerService _loggerService;
public LogBackgroudService(DbLoggerService loggerService)
{
_loggerService = loggerService;
}
protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
while (!stoppingToken.IsCancellationRequested)
{
try
{
await _loggerService.WriteLogsToDatabase(stoppingToken);
}
catch (Exception ex)
{
Console.WriteLine("Error: {0}", ex.ToString());
}
await Task.Delay(5_000, stoppingToken);
}
}
}LogBackgroudService artık bu işin son aşaması. 5 saniyede bir çalışan servis loglarımızı DbLoggerService içerisindeki WriteLogsToDatabase method’u ile database’e yazıyor.
Ne yapmış olduk?
ILogger (Microsoft.Extensions.Logging) kullanarak database üzerine asenkron bir şekilde loglama yaptık. Asenkron derken başka bir thread üzeride T0 anında başlayan bir loglamadan bahsetmiyorum. Microservice mimarisinden aşina olduğumuz tarzda bir eş zamansızlıktan bahsediyorum. Kuyruğa at ve unut… Bu işlemin bize response’larımızı hızlandırmamızda büyük katkısı oldu. Ancak doğada her zaman bir denge vardır. Ne zaman bir yapıda kazanç sağlasam diğer taraftan bir kayıp olduğunu düşünürüm. Burası doğa olmasa da; bu yapı da bize kısıtlamalar getirdi.
Neleri göze aldık?
Logların tutulduğu kuyruğun uygulama içerisinde olması fatal error’leri yakalayamadan kaybetmemiz anlamına geliyor. Örneğin uygulamanın bir nedenden dolayı çökmesi durumunda error logu sistem tarafından kuyruğa yazılır ancak background servisi çalışmayacağından database’e veri yazılamayacak.
Bir başka olumsuz yanı; uygulama ayağa kalkarken bir hata almamız durumunda henüz background service ve kuyruk oluşturulmadığından database’de log göremeyeceğiz.
Yine de bunlar çözülmeyecek sorunlar değiller. Örneğin fatal error’ler Windows Event Log üzerinden erişilebilir. Ya da uygulamanın onStopping gibi bir event’i esnasında araya girip kuyruktakileri db’ye yazmak da bir seçenek… Diğer sorun için; uygulama tamamen ayağa kalkana kadar varsayılan loglama uygulama ayağa kalktıktan sonra bu yapı kullanılacak şekilde ayarlanabilir.
Son olarak…
Yazılım geliştirmede bir amaca ulaşmanın bin bir türlü yolu var. Yaptığımız benchmark’lar sonucu en verimli yolun bu olduğuna karar verdik ve şu ana kadar kararımızdan pişman olmadık. Umarım da olmayız 😊 Eğer öyle bir durum olursa da kesinlikle ‘Hatalarımızdan Ders Alıyoruz’ başlıklı bir yazı gelir 😆 Umarım ihtiyacı olan birilerine farklı bir bakış açısı yaratabilmişimdir. Değerli vaktinizi ayırdığınız için teşekkürler…
