Alligator Swamp

技術メモ

複数のログファイルをtd-agentを使ってCloudWatch Logsに送る時にログファイル名をログストリーム名にする方法

ひと手間加える必要があったのでメモ。

バージョン

  • td-agent v3.8.1
  • fluent-plugin-cloudwatch-logs v0.13.0

方法

まずファイル名をタグに入れるために、 tagワイルドカードを指定する。こうすることで、フルパスが tag の末尾に追加される。(デリミタは . に変換される)

<source>
  @type tail
  format none
  pos_file /path/to/pos/foobar.pos
  path /path/to/log/*.log
  read_from_head true
  tag log.*
</source>

次に record_transformer を挟んでレコードにストリーム名を追加する。tail でタグにフルパスを含めたので、ファイル名の部分以降を tag_suffix で抜き出して指定する。

<filter log.**>
  @type record_transformer
  <record>
    stream_name ${tag_suffix[4]}
  </record>
</filter>

何故レコードにストリーム名を追加するかと言うと、 fluent-plugin-cloudwatch-logs には log_stream_name_key と言うオプションがあり、ここで指定したキーの値をストリーム名に使うことが出来るため。ストリーム名に使ったキーをCloudWatch Logsに残したくない場合は remove_log_stream_name_key も有効にする必要がある。

<match log.**>
  @type cloudwatch_logs
  log_group_name foobar
  log_stream_name_key stream_name
  remove_log_stream_name_key true
  auto_create_stream true
</match>

他にも use_tag_as_stream と言うオプションがあるが、これはタグすべてをストリーム名に使ってしまう。ファイル名だけにしたい場合は使うことが出来ない。

ISUCON10予選にk02で参加して敗退しました

ISUCON10予選にいつものメンバー(kyokomi, yasu)で参加して敗退した。
最終スコアは1,188で、全チーム(468チーム)の中では129番目。
初期スコアが500前後、予選通過ラインは2,100ぐらいだったので、良いとは言えないスコアかなと......。

ISUCON10 オンライン予選 全てのチームのスコア(参考値) : ISUCON公式Blog

準備したこと

今回はNew Relicさんが無料ライセンスを提供していたので、ありがたく使わせていただきました 🙏
事前にライセンスを発行し、ISUCON9のアプリに組み込んで、どのような情報が取れるかを確認。

ISUCON10参加者向けNew Relic特別無料ライセンスが利用可能となりました : ISUCON公式Blog

当日

初動

まずはいつも通りの対応

  • レギュレーションを読み込む
  • ドキュメントを読み込む
  • サーバにログインする設定を追加
  • アプリの動作確認
  • 構成の把握
  • GitHubにコードをpush
  • 修正入れずにベンチマークを実行

次に事前に準備したNew Relic関連を設定

  • New Relic Agentを全台に導入
  • アプリにNew Relicパッケージを導入

修正内容

分担しながら以下を実施

  • NginxでBotを弾く
  • MySQLを別サーバに移動
  • INDEXを貼って /api/estate/low_priced/api/chair/low_priced を改善
  • rent, width, height などを範囲ではなくIDで検索するようにする
    • 併せてINDEXも追加
  • 検索条件のjsonを毎回parseしないようにする
  • estateにgeometryのカラムを追加して、なぞって検索のN+1を解消
  • /api/recommended_estate/:id のクエリ改善(時間切れで修正間に合わず)

良かったこと

New Relicが便利

f:id:waniji:20201003020334p:plain
New Relicの画面

どこに時間がかかっているか、修正した結果どのように変化したかがとても分かり易かった。前回までは手元で集計・分析してSlackで共有していたが、その手間が省けて効率的に進めることが出来た。ただ、New Relic自体の習熟度が低かったので、活用しきれたとは言えなかったのは反省点。

毎回やっていることは詰まらず出来た

MySQLの分離、MySQLのスローログ分析などは毎回やっていて、手順もチームのScrapboxにまとまっているので、何も詰まらずに作業ができた。

反省点

MySQLの知識不足

Generated columnsDescending index はそもそも知らず、Geometry についてはヒィヒィ言いながら調べて対応したのでかなり時間がかかった。DB分割が出来ていればかなりスコアが上がったのでは......という気はするので、MySQLの知識不足がかなり痛かった。

問題解決までに時間がかかりすぎた

解説を見ていると、分かってはいたが修正が間に合わなかった事が多い事に気づいた。どの修正が一番効果的かをチームで話し合いながら進めたが、とにかく手を動かして改善をし続ける人が一人はいたほうが、結果的にスコアが伸びるかもしれない。(単純に実力不足というのもある。悲しい。)

ISUCON10 予選問題の解説と講評 : ISUCON公式Blog

おわりに

今回も楽しかったし悔しかった。
次回があればまた参加します。
運営の皆様お疲れさまでした。

ISUCON9予選にk02で参加して惨敗しました #isucon

いつものメンバーでISUCONに参加して惨敗しました。いつもどおりインフラ面を担当。
最大スコアは3,120で、最終結果は fail でした。

事前にやったこと

  • チームで集まって打ち合わせとISUCON8予選を軽く解く
  • Prometheus + Grafana を使うことに決めたので、使用方法を調査
  • 当日やることの手順を scrapbox にまとめる (分析ツールのインストールや使用方法など)

当日やったこと

10:00-10:30

  • マニュアルを読んで気になった点をまとめる
  • テーブルのCREATE文やレコード数、レコード内容を scarpbox にメモ
  • categories が更新されないことに気づく

10:30-11:00

  • アプリケーションを触って動作確認
  • 決済が動かず悩んだが、pyament-service の url が開発用になってないことに気づく
  • QRコードを読み込み、発送完了に出来たことを喜ぶ

11:00-11:30

  • kataribe 入れた
  • hostnamectl で各サーバの名前をわかりやすくした
  • MySQL を 別サーバに移し始める

11:30-12:30

  • Alibaba Cloud のセキュリティグループをいじって 3306 ポートを許可する
  • MySQL の bind-address を 0.0.0.0 にして動き始める
  • ベンチを実行して、MySQL の slowlog と Nginx log の分析
  • DBサーバのCPUが200%近かったので、DBがボトルネックと判断

12:30-13:30

  • お昼ごはんを買いに行く
  • 作戦会議

13:30-14:30

  • デプロイしてログの分析を何度か行う
  • 合間に Prometheus の node-exporter と mysql-exporter を入れた

14:30-15:30

  • そろそろ campaign の値を変えておきたいねということで 1 にする
    • リクエスト傾向が変わり、Appサーバにボトルネックが移る
    • もっと早く試しておけばと後悔
  • Too many open files が出たので、systemd の LimitNOFILE の設定を nginx, isucari, mysql に設定
  • MySQL の max connections を増やした
  • shippment service が APIGatewayError(502) で死に始める

16:00-17:00

  • shipment service の status 遷移を見て、initial, wait_pickup, done は api 叩かなくて良いのではという話をする
  • App 二台構成にしようとして、画像の配信でエラーになったので戻す

17:00-18:10

18:10

  • おわり

反省点

  • 各種ツールのインストールが遅すぎた。スクリプト組むなり ansible 使うなりして最速で終わらせるべきだった。
  • campaign の値を変えるのが遅すぎた。単に負荷が上がるだけだと勘違いしていたのがそもそもの間違い。
  • 外部サービスのチェックが甘かった。業務だと気を使うのに、ISUCONでは何も問題なく動くと信頼しきっていた...。
  • App2台の構成にできなかった。画像の共有どうしようか、WebDavか、とか考えていたが、そもそも重い処理だけ振り分ければよかった。
  • アプリの調査に時間を使いすぎて、インフラの改善が疎かになった。インフラ担当なので、インフラの改善をもっとすべきだった。

次回に向けて

具体的な反省点が見つかったので、次回は改善して挑みたい。悔しい。

ISUCON8本戦にk02で参加し惨敗しました(15位)

f:id:waniji:20181023001847p:plain 初の本戦出場、スコアは5,124で順位は30組中15位でした。
シェアボタンを有効に出来ず勝負の土俵に立てなかったので、非常に悔しいです。

当日やったこと

[10:00 - 10:30]

  • ポータルサイトにログインしてレギュレーションを読む
  • 初期状態でベンチ実行
  • isuconユーザーに公開鍵認証でログインできるようにする
  • 全台でmysqldumpを実行

[10:30 - 11:00]

  • アプリケーションを操作して挙動を確かめる

[11:30 - 12:00]

  • サーバの情報をKibelaにまとめる
  • ベンチ前後のDBデータ件数などをKibelaにまとめる

[12:00 - 13:00]

  • ランチ兼ねて作戦会議
  • ここからアプリ担当(kyokomi,yasu)とインフラ担当(waniji)に分担

[13:00 - 13:30]

  • MySQLをDockerから切り離して別サーバに構築

[13:30 - 14:30]

  • MySQLのスロークエリを有効にしてmysqldumpslowで分析
  • SHOW CREATE TABLEの結果をKibelaにまとめる

[14:30 - 15:00]

  • NginxをDockerから切り離す

[15:00 - 16:00]

  • Nginxで静的ファイルを配信したが、何故かレイアウトが崩れてしまい戻す
  • ここで大幅なロス

[16:00 - 17:00]

  • sendfile, tcp_nopush, keepalive_timeout の設定を追加
  • Nginx+Appが1台、Appのみが2台、DBが1台の構成にする
  • 再起動用の設定を全台に行う

[17:00 - 18:00]

  • シェアボタンを有効にするもエラー多発で戻す

良かった点

  • Kibelaに情報をまとめた
    • Slackだと流れてしまう情報が見やすく便利だった
  • 各種計測ツールをスムーズに導入することが出来た
    • 事前練習の賜物

悪かった点

  • WEBサーバ3台+DBサーバ1台という構成にとらわれすぎた
    • 想定解法がMySQLのmaster/slaveだったが考えつかなかった
  • CPUに余裕があることに対し早めに疑問を持てなかった
    • 早々にシェアボタンを有効にしてボトルネックを調査すればよかった
  • シェアボタンの部分開放が思いつかなかった
    • 業務で10%開放のケースはよくあるのに何故思いつかなかったのか...
  • パーティションまで手が回らなかった
    • ここは気付いて後回しにしてしまったがゆえに悔しい...
  • 1つ1つの作業が遅かった
    • インフラ側の作業をもっと早く終わらせるべきだった
    • 日々の鍛錬が足りない

最後に

問題、会場、運営、どれをとっても素晴らしく、有意義な時間を過ごすことが出来ました。
次回があるならば必ずリベンジします。悔しい。 f:id:waniji:20181020193432j:plain f:id:waniji:20181020194230j:plain f:id:waniji:20181023002133j:plain

ISUCON8にk02で参加し予選突破しました

k02 (kyokomi, yasu, waniji) で参加するのは4回目で、今回は初の予選突破をしました。とても嬉しい。スコアは 39,282 で、528組中16位でした。

準備や当日やったことはチームメンバーの記事が詳しいので、そちらを見てください。

ここでは自分がやったことや反省点などをまとめておこうと思います

事前準備

  • ホワイトボードのある会場を確保
  • 外部ディスプレイ確保

いつも作業している環境が一番捗るため、外部ディスプレイをまず確保しました。また、お互いの画面を見ながらコミュニケーションをしたいので、横並びで席を配置しました。非常に気持ちよく作業出来たので、自分が一番貢献したのはこの部分かもしれません。

当日

  • レギュレーションとマニュアルの読み込み
  • アプリケーションを実際に動かしてみる
  • サーバ内で起動しているミドルウェア等々の把握
  • DBスキーマソースコード、initialize処理の把握

まずはサービス内容の理解に力を入れました。過去参加した時の反省会で、サービス理解が足りなかったという意見が毎回出ていたため、しっかりと時間を使いました。結果として、修正ミスがあったときにも素早く挽回が出来ていたので、初手としては成功でした。

  • h2oはほぼ手を加えない判断をした

Nginxに置き換える案も出たのですが、今回はここがポイントではないと判断し、ほぼ何もしませんでした。

  • MariaDBを別サーバで起動するようにした

ベンチマーク時のDB負荷がかなり高かったため、別サーバで動かすようにしました。そこまで苦戦することなく作業できたので一安心。

  • スロークエリログを出して改善案を出した

今回は Go を選択したのですが、バリバリかけるのが kyokomi のみだったので、自分と yasu はクエリのチューニングにまわりました。実装を任せきりにしてしまったため、分担としてはあまり良くなかったのかなと反省しています。

反省点

  • 作業分担があまり良くなかった

自分は、デプロイ改善やログの分析などに回ったほうが良かったなと思いました。ついついソースコードを読んで改善出来る箇所を探してしまうのですが、もっとメンバーを信頼して、サポート側に振ったほうが良かったなと反省しています。

  • 事前準備が足りなかった

もっとあんちょこを用意すべきでした。ISUCON終了時はモチベーションも上がり色々と必要なものが思い浮かぶのですが、一年経つと一切合切忘れてしまうので、次からは気をつけたいです。

感想

毎回参加して思うのですが、ISUCONは本当に楽しいです。運営の方々、ありがとうございます。念願の本戦出場なので、万全の体制で挑みたいです。

YAPC::Asia Tokyo 2015 に行ってきた

1日目(+懇親会)、2日目と参加してきた。 参加したトークは以下。

同時通訳はトーク動画には入らないと思ったので、迷った時は海外ゲストのトークを聞きに行った。同時通訳最高でした。後はPerl6のトークも優先した。

Larry Wall氏のトークで、Perl6のリリース時期が2015年のクリスマスと発言されたのもあって、Perl6に俄然興味が出てきた。Jonathan Worthington氏の、Perl6の並行/並列/非同期処理の話もとても興味深かった。

コミケに行かなかったので手に入れられなかった「雅なPerl入門第3版」がありがたいことに頒布されていたので購入。こちらにもPerl6入門の章があったので、リリース前に入門してみようと思う。

懇親会では、今までは基本的に知り合いと話すのがメインだったが、今回は初めて合う人と話をすることが多く、内容も充実していて、とても有意義だった。

EC2上のログをtd-agent使ってCloudWatch Logsに投げようとしたらSSL認証エラーになった話

EC2上のログを、td-agentfluent-plugin-cloudwatch-logsを使ってCloudWatch Logsに送信しようとしたところ、SSL認証エラーが発生したので、エラーの解決方法を調べたのでまとめてみた。間違っている箇所があれば指摘ください!

before_shutdown failed error="SSL_connect returned=1 errno=0 state=SSLv3 read server certificate B: certificate verify failed"

tl;dr

EC2でtd-agent使ってCloudWatch Logsにログを送信する場合は、/etc/sysconfig/td-agentに以下を追記すると上手くいくはず。

export SSL_CERT_FILE=/etc/pki/tls/cert.pem

バージョン情報

  • Amazon Linux AMI 2015.03
  • td-agent 2.2.0-0
  • fluent-plugin-cloudwatch-logs 0.0.7

エラー解消までの道のり

使用している証明書の確認してみる

td-agentに同梱されているrubyがどの証明書を使用しているかを確認。

$ /opt/td-agent/embedded/bin/ruby -r openssl -e 'p OpenSSL::X509::DEFAULT_CERT_FILE'
"/opt/td-agent/embedded/ssl/cert.pem"

td-agentに同梱されている証明書を使用しているようだ。

EC2組み込みの証明書を使用してみる

EC2の証明書は以下のパスにある。

/etc/pki/tls/cert.pem

OpenSSL::X509::DEFAULT_CERT_FILE_ENVで指定される文字列名で環境変数を指定すると、rubyが使用する証明書を変更できるのでそれを使う。

$ ruby -r openssl -e 'p OpenSSL::X509::DEFAULT_CERT_FILE_ENV'
"SSL_CERT_FILE"

td-agentはinitスクリプト内で/etc/sysconfig/td-agentを読み込むので、そこに以下の設定を書く

export SSL_CERT_FILE=/etc/pki/tls/cert.pem

td-agentを再起動して確認

service td-agent restart

td-agentを実行すると正常にログを送信することが出来た。

その他調べたこと

aws-sdk-rubyに証明書がバンドルされていないのか

aws-sdk-v1ではバンドルされていたが、aws-sdk-v2からバンドルしなくなった。

なぜaws-sdk-v2から証明書がバンドルされなくなったのか

証明書をバンドルすることで、SDKがセキュリティ上の懸念と責任を持つことになるので、望ましくないとのこと。(英語読み間違えてたらすみません)

なぜfluent-plugin-s3ではエラーにならないのか

fluent-plugin-s3はaws-sdk-v1を使用しているため。

fluent-plugin-cloudwatch-logsもaws-sdk-v1を使用すればよいのでは

aws-sdk-v2にしかCloudWatch Logsの実装は組み込まれてなくて、v1にバックポートもする予定ないらしい。

Amazon Linux以外のOSだとどうなの?

手元のMacでCentOS6.6の環境を作って試したけど、認証エラーが発生した。Amazon Linux以外では、aws-sdk-v1にバンドルされてる証明書を使わないとダメかもしれない。

CloudWatch Logs Agentはなんで大丈夫なの?

CloueWatch Logs AgentとはAWS公式のログ収集エージェント。内部的にはaws-cli(Python製)が使われている。aws-clibotocoreというAWS Interfaceライブラリを使用しており、それが証明書をバンドルしているので問題ない。