Nomad に載った API サーバーのログ監視を考える

Slack に通知をする

これを使う。
github.com

<source>
@type forward
port 24224
bind 0.0.0.0
</source>
<filter *.**>
@type parser
<parse>
@type json
json_parser oj
time_format %Y-%m-%dT%H:%M:%S
</parse>
key_name log
replace_invalid_sequence true
emit_invalid_record_to_error true
reserve_data true
</filter>
<filter *.**>
@type grep
<exclude>
key caller
pattern /^$/
</exclude>
</filter>
<match **.*>
@type copy
<store>
@type elasticsearch
host elasticsearch.luis.local
port 9200
logstash_format true
logstash_prefix fluentd
logstash_dateformat %Y%m%d
include_tag_key true
type_name fluentd
tag_key @log_name
flush_interval 1s
log_es_400_reason true
<buffer>
@type memory
flush_thread_count 4
</buffer>
</store>
<store>
@type slack
webhook_url
channel easyuploader
username "easyuploader api"
color danger
icon_url
flush_interval 1s
title_keys func
title "Error in %s"
message_keys msg,func,error,client,ua
message "*%s in %s*\n*err:* %s\n*ip:* %s\n*ua:* %s"
<buffer>
@type memory
flush_thread_count 4
</buffer>
</store>
</match>

ネストされた JSON を展開する

{
"_index": "fluentd-20200106",
"_type": "_doc",
"_id": "XsbPem8B4S2PoHfN9N2k",
"_version": 1,
"_score": null,
"_source": {
"container_id": "6b35a88f599432b461bfd7f1cf54a167f60840deb5dfb409a066739cb891de18",
"container_name": "/prd-31491e51-65c3-2893-afc0-4bc4f8219a5b",
"source": "stderr",
"log": "{\"level\":\"error\",\"ts\":1578312131.531616,\"caller\":\"lib/logger.go:22\",\"msg\":\"GetUploadInfo\",\"func\":\"Delete\",\"error\":\"record not found\",\"client\":\"\",\"ua\":\"Mozilla/5.0 (iPad; CPU OS 10_3_3 like Mac OS X) AppleWebKit/603.3.8 (KHTML, like Gecko) Version/10.0 Mobile/14G60 Safari/602.1\",\"stacktrace\":\"github.com/rluisr/easyuploader_api/lib.logger\\n\\t/go/src/easyuploader_api/lib/logger.go:22\\ngithub.com/rluisr/easyuploader_api/lib.ErrorWithResponseInternalServer\\n\\t/go/src/easyuploader_api/lib/logger.go:30\\ngithub.com/rluisr/easyuploader_api/resource.Delete\\n\\t/go/src/easyuploader_api/resource/delete.go:22\\nmain.main.func9\\n\\t/go/src/easyuploader_api/main.go:73\\ngithub.com/gin-gonic/gin.(*Context).Next\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\\ngithub.com/gin-gonic/gin.RecoveryWithWriter.func1\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:83\\ngithub.com/gin-gonic/gin.(*Context).Next\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\\ngo.elastic.co/apm/module/apmgin.(*middleware).handle\\n\\t/go/pkg/mod/go.elastic.co/apm/module/[email protected]/middleware.go:132\\ngithub.com/gin-gonic/gin.(*Context).Next\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\\ngithub.com/gin-gonic/gin.(*Engine).handleHTTPRequest\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:389\\ngithub.com/gin-gonic/gin.(*Engine).ServeHTTP\\n\\t/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:351\\nnet/http.serverHandler.ServeHTTP\\n\\t/usr/local/go/src/net/http/server.go:2802\\nnet/http.(*conn).serve\\n\\t/usr/local/go/src/net/http/server.go:1890\"}",
"level": "error",
"ts": 1578312131.531616,
"caller": "lib/logger.go:22",
"msg": "GetUploadInfo",
"func": "Delete",
"error": "record not found",
"client": ",
"ua": "Mozilla/5.0 (iPad; CPU OS 10_3_3 like Mac OS X) AppleWebKit/603.3.8 (KHTML, like Gecko) Version/10.0 Mobile/14G60 Safari/602.1",
"stacktrace": "github.com/rluisr/easyuploader_api/lib.logger\n\t/go/src/easyuploader_api/lib/logger.go:22\ngithub.com/rluisr/easyuploader_api/lib.ErrorWithResponseInternalServer\n\t/go/src/easyuploader_api/lib/logger.go:30\ngithub.com/rluisr/easyuploader_api/resource.Delete\n\t/go/src/easyuploader_api/resource/delete.go:22\nmain.main.func9\n\t/go/src/easyuploader_api/main.go:73\ngithub.com/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\ngithub.com/gin-gonic/gin.RecoveryWithWriter.func1\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/recovery.go:83\ngithub.com/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\ngo.elastic.co/apm/module/apmgin.(*middleware).handle\n\t/go/pkg/mod/go.elastic.co/apm/module/[email protected]/middleware.go:132\ngithub.com/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:124\ngithub.com/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:389\ngithub.com/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:351\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2802\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:1890",
"@timestamp": "2020-01-06T12:23:11.429817368+00:00",
"@log_name": "eu-prd-api"
},
"fields": {
"@timestamp": [
"2020-01-06T12:23:11.429Z"
]
},
"sort": [
1578313391429
]
}

log の中身に全部入ってるが、それを ↓ によってパースしている。
その結果、msg とか func が展開された。

<filter *.**>
@type parser
<parse>
@type json
json_parser oj
time_format %Y-%m-%dT%H:%M:%S
</parse>
key_name log
replace_invalid_sequence true
emit_invalid_record_to_error true
reserve_data true
</filter>

が、パラメータとかはよく分かってない。

アプリのログ以外は無視したい

<filter *.**>
@type grep
<exclude>
key caller
pattern /^$/
</exclude>
</filter>

caller がないときは無視する。

Elasticsearch に送りながら Slack に送る

<match **.*>
@type copy
<store>
@type elasticsearch
host elasticsearch.luis.local
port 9200
logstash_format true
logstash_prefix fluentd
logstash_dateformat %Y%m%d
include_tag_key true
type_name fluentd
tag_key @log_name
flush_interval 1s
log_es_400_reason true
<buffer>
@type memory
flush_thread_count 4
</buffer>
</store>
<store>
@type slack
webhook_url
channel easyuploader
username "easyuploader api"
color danger
icon_url
flush_interval 1s
title_keys func
title "Error in %s"
message_keys msg,func,error,client,ua
message "*%s in %s*\n*err:* %s\n*ip:* %s\n*ua:* %s"
<buffer>
@type memory
flush_thread_count 4
</buffer>
</store>
</match>

確認

Slack 上では必要最低限な情報に留めて、Stack trace は Kibana 上で確認できるように ts を載せる。
出来れば footer, author で Kibana の該当レコードへのリンクとか貼りたい。

Tips

これを実現するために改修したこと

func logger(funcName, msg, clientIP, ua string, err error) {
slogger.Errorw(msg,
"func", funcName,
"error", err,
"client", clientIP,
"ua", ua)
}
func ErrorWithResponseInternalServer(c *gin.Context, funcName, msg, resMsg string, err error) {
logger(funcName, msg, c.ClientIP(), c.Request.UserAgent(), err)
c.JSON(http.StatusInternalServerError, resMsg)
}
func ErrorWithResponseBadRequest(c *gin.Context, funcName, msg, resMsg string, err error) {
logger(funcName, msg, c.ClientIP(), c.Request.UserAgent(), err)
c.JSON(http.StatusBadRequest, resMsg)
}

func main() {
router := gin.New()
srv := &http.Server{
Addr:    addr,
Handler: router,
}
go func() {
if err := srv.ListenAndServe(); err != nil {
log.Printf("listen: %s\n", err)
}
}()
quit := make(chan os.Signal, 1)
signal.Notify(quit, os.Interrupt)
<-quit
log.Println("Shutdown Server ...")
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
defer cancel()
if err := srv.Shutdown(ctx); err != nil {
log.Fatal("Server Shutdown:", err)
}
log.Println("Server exiting")
}

router.ForwardedByClientIP = true

// ClientIP implements a best effort algorithm to return the real client IP, it parses
// X-Real-IP and X-Forwarded-For in order to work properly with reverse-proxies such us: nginx or haproxy.
// Use X-Forwarded-For before X-Real-Ip as nginx uses X-Real-Ip with the proxy's IP.
func (c *Context) ClientIP() string {
if c.engine.ForwardedByClientIP {
clientIP := c.requestHeader("X-Forwarded-For")
clientIP = strings.TrimSpace(strings.Split(clientIP, ",")[0])
if clientIP == "" {
clientIP = strings.TrimSpace(c.requestHeader("X-Real-Ip"))
}
if clientIP != "" {
return clientIP
}
}
if c.engine.AppEngine {
if addr := c.requestHeader("X-Appengine-Remote-Addr"); addr != "" {
return addr
}
}
if ip, _, err := net.SplitHostPort(strings.TrimSpace(c.Request.RemoteAddr)); err == nil {
return ip
}
return ""
}

[entryPoints.http.forwardedHeaders]
insecure = true