Mikroservislerde Logging

Log konusu mikroservisler için çözülmesi en karmaşık konulardan biridir. Mikroservisler mümkün olduğunca saf kalmalı. Yani mümkünse logging, monitoring vs. gereksinimler için ekstra kütüphane eklemekten kaçınmalıyız. Bu bağımlılıklar her an değişiklik gösterebilir ve bu durumda tüm mikroservisler üzerinde değişiklik yapmamız gerekebilir. Bu da çok fazla iş yapmak demek olurdu. Bunun yerine bu bağımlılıkları daha generic yollarla çözmeliyiz. Logging için bunun yolu “stdout” a yazmak. Çoğu programlama dili için bu varsayılan yoldur ve çoğu zaman, başlangıçta bir değişiklik de gerektirmez.

Genelde kullandığımız log kütüphaneleri logu belirli bir süre ramde tutar ve sonrasında log servera gönderir.

Çoğumuzun en çok kullandığı sistem de bu şekilde. Aslında monolith uygulamalar için basit ve oldukça etkili bir yöntem. Kaba tabirle “iş görüyor” da diyebiliriz. Ekstra bir efor gerektirmiyor, loglar uygulama memorysinde structural olarak duruyor ve bu işlem için de ekstra bir uğraşa gerek kalmıyor.

Peki ya birçok mikroservisimiz olsa ve hiç kod değişikliği yapmadan bu servislere log yapısını entegre etmemiz gerekse? Loglama ile ilgili herhangi bir değişiklik gerektiğinde bunu tüm servislere uygulamanız gerektiğini ve hepsini deploy etmeniz gerektiğini düşünün. Peki ya birden fazla dille servis yazıyorsanız? Bu defa kullandığınız her dil için bir logging yapısı kurmak veya farklı log kütüphanesi bulup kullanmak zorunda kalacaktınız.

In short, the microservice architectural style is an approach to developing a single application as a suite of small services, each running in its own process and communicating with lightweight mechanisms, often an HTTP resource API. There is a bare minimum of centralized management of these services, which may be written in different programming languages. #Martin Fowler

Bu sepeblerden ötürü, loglarımızı konsola(aslında dosyaya) yazıp unutacağız. Bir log toplayıcı da bizim için bu logları belirli zaman aralıklarında toplayacak.

Burada iki problem var. Logları konsoldan nasıl toplayacağımız ve bu loglara header cookie ve timestamp gibi alanları nasıl ekleyeceğimiz.

Logları Konsoldan Nasıl Toplarız?

Bu işi yapan çok araç var. En popüler olanları Logstash ve Fluentd diyebilirim. Mesela eğer mikroservislerinizi k8s kullanarak containerlarda host edecekseniz her iki aracın da containerlardan log toplayan implementasyonları(Filebeat/Fluentbit) var. Biz şimdi Filebeat üzerinden ilerleyeceğiz. Filebeat, log dosyalarındaki logları Logstashe iletmekle görevli.

Docker containerlar için konsola loglamak demek logu dosyaya yazmak demek. Docker olmayan bir ortamda çalışıyorsanız logları dosyaya yazdırmak için birkaç ayar yapmanız gerekebilir.

Logları konsoldan okurkenki en büyük problem ise, hangi log satırının hangi loga ait olduğunu doğru olarak belirleyebilmektir. Özellikle hata logları gibi birden fazla log satırı içerebilen loglarda. Örnek bir hata logu:

Basit bir go apisinden panic çağrımı yapıldığında.

Multiline Patterns

Çözüm basit. Filebeatin sunduğu multiline pattern yapısını kullanacağız. Bu patternler yeni log satırının nerede başlayıp nerede bittiğini belirtmeye yarıyor. Yukarıdaki log satırılarını okumak için şöyle bir pattern tanımlamak gerekir:

multiline.pattern: '^([12]\d{3}\/(0[1-9]|1[0-2])\/(0[1-9]|[12]\d|3[01]))'
multiline.negate: true
multiline.match: after

Filebeat, burada belirtilen tarih formatında(yyyy/mm/dd) olmayan(negate:true) tüm log satırları boyunca okumaya devam eder ve tarih içeren başlangıç satırını da dahil ederek(match:after) logu bütün olarak okumuş olur.

Filebeat multiline pattern hakkında daha fazla detay için:

Manage multiline messages | Filebeat Reference [7.3] | Elastic

Sıradaki adım ise bu ham datayı fieldlarına ayırmak, structured yapmak. Yani hangi parçası mesaj, hangi parçası hata bunları ayıklamak.

Log Mesajını Structured Yapmak

Elimizde tam bir loga ait olan string var. Bu stringi logun fieldları olacak şekilde ayırmak arama, görüntüleme ve kolay erişim açısından çok önemli.

Grok filters ile tanışın! Grok, bir text pattern ile çalışır ve bu patterne göre, girilen stringi fieldlara ayırmaya yardımcı olur.

Logstash grok filter pluginini kullanabilirsiniz.

Aşağıda bir örnek text, grok pattern ve çıktısını görebilirsiniz.

Örnek text:

2019/08/12 21:01:27 http: panic serving [::1]:50206: Something went wrong :/
goroutine 5 [running]:
net/http.(*conn).serve.func1(0xc00008c8c0)
 /usr/local/Cellar/go/1.11.1/libexec/src/net/http/server.go:1746 +0xd0
panic(0x1245ea0, 0x12eb9a0)

Grok pattern:

%{DATESTAMP:log_date} %{GREEDYDATA:message}(\n(?m)%{GREEDYDATA:exception})

Sonuç:

{
  "log_date": [
    [
      "19/08/12 21:01:27"
    ]
  ],
  "message": [
    [
      "http: panic serving [::1]:50206: Something went wrong :/"
    ]
  ],
  "exception": [
    [
      "goroutine 5 [running]:\nnet/http.(*conn).serve.func1(0xc00008c8c0)\n /usr/local/Cellar/go/1.11.1/libexec/src/net/http/server.go:1746 +0xd0\npanic(0x1245ea0, 0x12eb9a0)"
    ]
  ]
}

Bundan sonra, log detayları fieldlara ayrıldı ve elasticsearche ya da istediğiniz bir log servera yazdırılmaya hazır. Logstashe bir output ayarı verdiyseniz Logstash bu kısmı halledecektir. Bir sonraki adım ise bu logları görüntülemek fakat bu yazıda bu konuya girmeyeceğim.

Loglarınızı kibanada görüntüleyecekseniz, kibananın nested fields deteği olmadığını söylemeliyim.

Header, Cookie ve Timestamp gibi Alanları Loglara Nasıl Ekleriz?

Çoğu programlama dili için stdout loglarına mesaj ve hata detayı dışında bir şey yansıtılmaz. Bu loglara daha fazla field eklemek için default logger override edilmelidir.

Golang için bir örnek üzerinden nasıl yapıldığını inceleyelim. Kod şu şekilde dizayn edilebilir:

Yukarıdaki kodda log, istediğimiz formatta konsola yazılıyor. Bu işlem sırasında x-request-id headerındaki değer de loga ekleniyor. Bir de hata logu için error: ile başlanıyor ve böylece hem okurken hem de grok ile anlamlandırırken bu işimizi kolaylaştırıyor. Kısacası logu şu formatla oluşturmuş olduk:

level: timestamp request_id "message" \nstack_trace

İçerisinde sadece panic çağrısı olan index metoduna basit bir istek atalım ve sonucu inceleyelim.

curl -H "x-request-id:a56bc-99hx0" localhost:8000

Bu log çıktısı için ise multiline pattern şu şekilde olmalı:

multiline.pattern: '^error:|^info:'
multiline.negate: true
multiline.match: after

Fieldları doğru bir şekilde eşleştirmek için grok pattern ise:

%{WORD:log_level}: %{TIMESTAMP_ISO8601:log_date} %{DATA:request_id} %{DATA:msg}(\n(?m)%{GREEDYDATA:exception})

Bonus: Kibanada ise şu şekilde görüntülenebilir:

@ timestamp ve log_date fieldları fark gösterebilir. log_date uygulama seviyesindeki tarihi gösterir. timestamp ise Logstash tarafından sağlanan tarih alanıdır. @ version _id _index _score ve _type ise varsayılan fieldlardır.

Linkler:

https://cloud.docker.com/repository/docker/turgayozgur/goexample
https://martinfowler.com/articles/microservices.html
https://www.elastic.co/products/beats/filebeat
https://www.elastic.co/products/logstash
https://www.elastic.co/products/elasticsearch
https://www.elastic.co/products/kibana
https://grokdebug.herokuapp.com/
https://fluentbit.io/