ネットで調べて、Cloudwatch Logsのサブスクリプションフィルタ+Lambda連携で、エラー関連の文字列を拾ったらSlack通知するようにしてみた。この辺は試行錯誤中なので気が向いたらまた書きたいと思う。で、エラーがSlackに通知されることはいいものの、以下で悩む
- スタックトレースが出力された場合、スタックトレースの全文ではなく、1行1行に対してフィルタが適用されて、設定した文字列に該当する部分が断片的に通知されてしまう
- 大量のエラーが出力された場合、Slackチャンネルが大変なことになる
後者は、例えば同じエラーメッセージが短時間に連続した場合、通知を1回にまとめるという仕組みが取れるといいんだけど、サブスクリプションフィルタではどうにもならないので別の仕組みが必要。ネットで調べてもあまり事例出てこない.. Zabbixとかの事例はあるんだけど。Fluentd使ってる方で、その対策に自作でプラグイン作ったというのがあった。うーん、やはりそういう対策は適当なものはないものなのか..?
前者については、たとえば以下のようなスタックトレースが出力されたとして
(色々マスキングしてるので出力そのものにあまり意味はありません)
2021-12-17T14:15:57.912+09:00 2021-12-17 05:15:57.910 WARN 1 --- [nio-8080-exec-5] j.c.w.app.service.impl.PushHelper : Can not write record to repository
2021-12-17T14:15:57.912+09:00 software.amazon.awssdk.services.s3.model.S3Exception: We encountered an internal error. Please try again. (Service: S3, Status Code: 200, Request ID: xxxxxxxxxxxxxxx, Extended Request ID: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx)
2021-12-17T14:15:57.912+09:00 at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleErrorResponse(AwsXmlPredicatedResponseHandler.java:156) ~[aws-xml-protocol-2.17.100.jar!/:na]
2021-12-17T14:15:57.912+09:00 at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleResponse(AwsXmlPredicatedResponseHandler.java:106) ~[aws-xml-protocol-2.17.100.jar!/:na]
2021-12-17T14:15:57.912+09:00 at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handle(AwsXmlPredicatedResponseHandler.java:84) ~[aws-xml-protocol-2.17.100.jar!/:na]
2021-12-17T14:15:57.912+09:00 at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handle(AwsXmlPredicatedResponseHandler.java:42) ~[aws-xml-protocol-2.17.100.jar!/:na]
2021-12-17T14:15:57.912+09:00 at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler$Crc32ValidationResponseHandler.handle(AwsSyncClientHandler.java:95) ~[aws-core-2.17.100.jar!/:na]
... 省略
2021-12-17T14:15:57.912+09:00 at org.vendor.engine.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540) ~[vendor-core-0.0.00.jar!/:na]
2021-12-17T14:15:57.912+09:00 at org.vendor.engine.core.StandardHostValve.invoke(StandardHostValve.java:135) ~[vendor-core-0.0.00.jar!/:na]
2021-12-17T14:15:57.912+09:00 at org.vendor.engine.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[vendor-core-0.0.00.jar!/:na]
2021-12-17T14:15:57.912+09:00 at org.vendor.engine.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[vendor-core-0.0.00.jar!/:na]
2021-12-17T14:15:57.912+09:00 at org.vendor.engine.connector.frontAdapter.service(frontAdapter.java:357) ~[vendor-core-0.0.00.jar!/:na]
2021-12-17T14:15:57.912+09:00 at org.vendor.front.http11.Http11Processor.service(Http11Processor.java:382) ~[vendor-core-0.0.00.jar!/:na]
... 省略
2021-12-17T14:15:57.912+09:00 at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]
サブスクリプションフィルタでERRORとErrorを定義していた場合、Lambda経由でSlackに以下通知が来る
2021-12-17 14:15:57 [CloudWatch Log Alarm] /ecs/LOGGROUP / ecs/CONTAINER/STREAMINGGROUP nLogMessages:n
2021-12-17 05:15:57.910 WARN 1 --- [nio-8080-exec-5] j.c.w.app.service.impl.PushHelper : Can not write record to repository
at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleErrorResponse(AwsXmlPredicatedResponseHandler.java:156) ~[aws-xml-protocol-2.17.100.jar!/:na]
at org.vendor.middleware.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.55.jar!/:na]
at software.amazon.awssdk.protocols.xml.internal.unmarshall.AwsXmlPredicatedResponseHandler.handleErrorResponse(AwsXmlPredicatedResponseHandler.java:156)
at org.vendor.middleware.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
なにがいいたいかというと、実際のスタックトレースに対して、定義した文字列が含まれる行だけが断片的に通知されているのと、なぜか通知側の最終2行はスタックトレースの同じ内容を2回送って来てる。これは意味不明。
利用してるライブラリのパスにErrorなどといった文字列が含まれてる場合、その行の通知が断片的に来てる。これは仕方ないのだが、ログチェック的には単純に2行目以降は連続してない意味のないスタックトレースが送られてしまっていて見づらい。
今回のログに限れば文字列の定義からErrorを外せばErrorがパスに含まれるスタック行を拾わなくはなりそうだけど..
ECSのログ監視、悩ましい