every Tech Blog

株式会社エブリーのTech Blogです。

Flutterアプリのログの出し方を整理した話

この記事はevery Tech Blog Advent Calendar 2024の21日目の記事です。

はじめに

こんにちは、リテールハブ開発部のネットスーパーチームでFlutterエンジニアをしている野口です。 今回は弊社で運用しているFlutterアプリのログの出し方を整理した際の話をします。

なぜログを整理するか

弊社で運用しているアプリの中で事業譲渡で引き継いだアプリがあります。 そのアプリは以下のように3つのパターンでログを出しており、統一されていませんでした。

統一されていないため以下のような問題があり、整理することにしました。

  • ログがどこで出てるのか把握しづらい
  • 開発者によって書き方が異なってしまう
  • エラーなどの問い合わせの際に、状況が把握できない

ログ整理の方針

ログを整理するにあたり、以下の理由でloggerに統一することにしました。

  • デフォルトでログレベルのサポートがある

loggerはデフォルトで以下のログレベルを提供しており、これを利用することでログの重要度に応じたログの出しわけができます。

ログレベルの種類

  • trace
  • debug
  • info
  • warning
  • error
  • wtf(What a Terrible Failure)

また、デフォルトでログレベルに合わせて色が変わるため視認性が良くなります。

実際にログを整理する

1. 不要なログ出力コードを整理

まず初めに、既存のログ出力をしている箇所で不要なログを削除しました。 printdeveloper.logの使用箇所はログ出力する意味がないものだったので削除しました。 loggerは例外処理のログ出力で使用していたので、後述のログ出力方法に置き換えるようにします。

2. ログの出力処理を一元化

次に、AppLogクラスを作成し、ログの出力処理を一元化しました。 これにより、統一された方法でログを出力できるようになり、誤った使い方を防ぐことができるようになります。

class AppLog {
  static final Logger _logger = Logger();

  static void debug({String message, StackTrace stackTrace}) {
    _log(message: message, level: Level.debug, stackTrace: stackTrace);
  }

  static void info({String message, StackTrace stackTrace}) {
    _log(message: message, level: Level.info, stackTrace: stackTrace);
  }

  static void error({String message, Exception exception, StackTrace stackTrace}) {
    _log(message: message, level: Level.error, exception: exception, stackTrace: stackTrace);
  }


  static void _log({String message, Level level, Exception exception, StackTrace stackTrace}) {
    if(!kReleaseMode){
      _logger.log(level, message, exception, stackTrace);
    }

    if(level.index >= Level.info.index && message != null) {
      FirebaseCrashlytics.instance.log(message);  
    }

    if (level.index >= Level.error.index && exception != null) {
      FirebaseCrashlytics.instance.recordFlutterError(FlutterErrorDetails(exception: exception, stack: stackTrace));
    }
  }
}

ログレベルはdebug、info、errorの3種類に分けており、_log関数の中でログレベルに応じて処理を分けています。

また、!kReleaseModeではリリースビルドでログを表示しないようにしており、本番環境では表示されないため、安心して使用できます。

debugログ

debugログは、主に開発時に変数の値やアプリの状態を確認したい場合に使用します。

if(!kReleaseMode){
  _logger.log(level, message, exception, stackTrace);
}

debugログの使用例:

void fetchData() {
  final data = {"key": "value"};
  AppLog.debug(message: "fetchData() called with data: $data");
}

infoログ

infoログは、アプリの動作状況やユーザーの操作イベントを記録したい場合に使用します。

また、Firebase Crashlyticsに情報を送信することで、本番環境での挙動を把握するのにも役立ちます。

if(!kReleaseMode){
  _logger.log(level, message, exception, stackTrace);
}

if(level.index >= Level.info.index && message != null) {
  FirebaseCrashlytics.instance.log(message);  
}

infoログの使用例:

void userLogin(String username) {
  AppLog.info(message: "User logged in with username: $username");
}

errorログ

errorログは、例外が発生した場合や補足したいエラーを記録する際に使用します。

また、Firebase Crashlyticsに例外情報を送信することで、問題を迅速にトラッキングできます。

if(!kReleaseMode){
  _logger.log(level, message, exception, stackTrace);
}

if (level.index >= Level.error.index && exception != null) {
  FirebaseCrashlytics.instance.recordFlutterError(FlutterErrorDetails(exception: exception, stack: stackTrace));
}

errorログの使用例:

void processPayment() {
  try {
    // エラーが発生する可能性のある処理
    throw Exception("Payment processing failed");
  } catch (e, stackTrace) {
    AppLog.error(
      message: "Payment error occurred",
      exception: e,
      stackTrace: stackTrace,
    );
  }
}

終わりに

今回はログの出し方を整理する話をしました。 ログの出し方を一元化したことで、ログの使い方が開発者に伝わりやすくなり、誤ったログの使い方を防ぐことができるようになりました。 さらに、以前は本番環境でユーザーがabd logcatなど使用すればログが見える状況でしたが、ログを本番環境で出ないようにし、誤ってユーザー情報がログ出力されるなどのリスクを防ぐことでセキュリティ面でも改善ができました。

ご覧いただきありがとうございました。

エブリー初のエンジニア向け内定者研修を実施しています

エブリー初のエンジニア向け内定者研修を実施しています

この記事は every Tech Blog Advent Calendar 2024 の 20 日目の記事です。

目次

はじめに

こんにちは。 トモニテ開発部ソフトウェアエンジニア兼、CTO室Dev Enableグループの庄司(ktanonymous)です。
現在弊社では、2025年新卒のエンジニア内定者向けに初めての内定者研修を実施しております。 今回の記事では、その内容について紹介したいと思います。

エンジニア内定者研修を実施するに至った背景

まずは、なぜこのタイミングで初めての内定者研修の実施を決定したのか、その背景についてお話ししたいと思います。

弊社では、今年の2月に、開発組織を横断して様々な課題解決を促進するための DevEnable というグループが立ち上がりました。 (以下の記事で DevEnable グループを設立した際の話について綴ってあります)

筆者も所属している DevEnable グループでは、新卒エンジニア向けのサポートも積極的に行っていきたいと考えています。 そんな中で今回のエンジニア内定者研修の実施に至ったのには、主に2つの理由があります。

1つ目の理由としては、これが一番大きいですが、内定者の意欲がありました。
内定者側から「学習機会があれば入社前でも積極的に利用していきたい」という意欲的な意見が上がっていました。 そういった意見を受けて、DevEnableとしても、内定者の積極性と学習意欲に応えたいと感じていました。
そこで、入社前の段階ではありますが、内定者向けに研修を実施するのが良いのではないかと考えました。

2つ目の理由として、今年度の初めに実施したエンジニア新卒研修での反省があります。
DevEnableグループの発足後、1つの新しい大きな取り組みとして、2024年新卒エンジニアの入社後のサポートをするために新卒エンジニア研修を実施しました。 (この新卒研修もエンジニア向けのものは初めてとなる取り組みでした。新卒研修の概要に関しては以下の記事をご覧ください)

それまでは、新卒全体での職能に依らない研修はこれまでも実施されていましたが、エンジニア向けの研修は行われておらず OJT でのオンボーディングが基本となっていました。 そのため、エンジニアにフォーカスした研修を実施したことで、エブリーのエンジニアとしてのマインドセットの獲得や 幅広い知識をインプットすることでスムーズな開発組織への参画をサポートすることができました。

一方で、先の記事でも触れている通り、専門領域外を含めて社内の実際の技術スタックに触れてもらったため、以下のようなネガティブなフィードバックもありました。

  • 最低限必要な知識などを事前に共有することで、もう一段階踏み込んだ講義内容になると感じた。
  • 研修で使用する各種ツールの使い方についての研修か資料があると取り組みやすいと思いました。

このようなフィードバックを受け、今後も入社後のより良い新卒研修を実施していくために、受講者の知識のベースラインを揃えておくことが重要ではないかと考えていました。

上記のように、内定者の意欲を受け、新卒研修でのフィードバックを参考にしてエンジニア向けの内定者研修を実施することを決定しました。

エンジニア内定者研修の概要

エンジニア内定者研修の目的

先述の通り、内定者研修では内定者の学習意欲に応えること、来年度入社する新卒のエンジニアメンバーが入社後の研修を通じてよりスムーズに開発組織にジョインできるように ベースとなる基礎知識を学べる機会を提供することを主な目的としています。
具体的には、以下のような目的と方針を設定しました。

目的
入社前に基本的な技術や知識をキャッチアップする環境を提供する

方針

  • 入社前に身に着けてほしい技術や知識のキャッチアップをサポートする
  • 基礎知識を早期にキャッチアップすることで入社後の研修・オンボーディングをよりスムーズに進められるようになる

上記の目的と方針を踏まえ、筆者を含めた新卒3年目までの若手メンバーが中心となり、研修を企画・運営しています。

エンジニア内定者研修カリキュラム

今回の研修では以下のテーマで講義を行うこととしました。 各回 2 時間を目安に、2 週間に 1 回のペースで実施しています。
(執筆現在、第6回まで完了しています)

  1. ターミナルおよび Git/GitHub の基礎
  2. ネットワーク/インフラ基礎
  3. DB 研修
  4. プログラム基礎
  5. Web 基礎
  6. Web アプリケーション開発基礎
  7. 個人開発

また、遠方から参加する方もいるため、全ての講義はオンラインで実施して録画を残すようにしています。 ただし、学業を優先してもらいたい思いもあったため、任意での参加としています。

terminal および Git/GitHub の基礎

terminal および Git/GitHub の講義では、下記のようなトピックを通じて、 普段から利用機会の多いCLI(ターミナル)やチームでの開発を行うにあたり弊社でも利用している Git/GitHub の基本的な使い方について学びました。

  • ターミナル/シェルとは何か
  • コマンドはどのようにして実行されているのか
  • 主要なコマンドの紹介
  • Git の基本的な仕組み
  • Git の基本的なコマンド
  • GitHub の使い方

ネットワーク/インフラ基礎

ネットワーク/インフラ基礎の講義では、OSI 参照モデルを中心に、 ネットワークやインフラの基礎知識について学びました。
具体的には以下のトピックを取り上げました。

  • プロトコル
  • TCP/IP
  • ネットワークセグメント
  • HTTP
  • アドレス

DB 研修

DB 研修では、DB の基本概念やバックエンド/データ系それぞれの視点での利用について学びました。 具体的には以下のトピックを取り上げました。

  • 「データ」の種類
  • データ基盤
  • サーバーエンジニア視点でのデータ利用
  • データエンジニア視点でのデータ利用

プログラム基礎

プログラム基礎の講義では、プログラムの基本的な構造やデータ構造、アルゴリズムについて学びました。 具体的には以下のトピックを取り上げました。

  • データ構造
    • 配列とリスト
    • スタックとキュー
    • ハッシュ
    • 木構造
  • アルゴリズム
    • ソート
    • 探索

Web 基礎

Web 基礎の講義では、API や Web アプリケーションの基本構成や仕組み、 バックエンド/フロントエンドそれぞれの役割について学びました。 具体的には以下のトピックを取り上げました。

  • Web アプリケーションの基本構成
    • ブラウザでの HTML のレンダリングについて
    • ブラウザとサーバーの通信について
    • ページの配信方式
  • フロントエンドとバックエンドの役割

Web アプリケーション開発基礎

Web アプリケーション開発基礎の講義では、アーキテクチャやテスト、コーディング時に意識することなど、 組織/チームでの開発に携わるうえで重要となってくる考え方について学びました。 具体的には以下のトピックを取り上げました。

  • 良いコードを書くために意識すること
  • アーキテクチャ
  • テスト
  • CI/CD

個人開発

個人開発では、入社までの期間を通じて、実際にアプリケーションを開発してもらう予定となっています。 (本記事執筆時点で開始前となっています)

受講者のフィードバック

研修の改善のために、受講者からのフィードバックをアンケートで収集しており、その中でも以下のようなポジティブな意見が見受けられました。

  • 以前勉強してから時間が経っていたので、いい復習になりました。それらの知識がエブリーの中でどういうところに当てはまっているのかも知ることができました。
  • 学校の授業ではあまりやらないような,実際のアプリケーション開発に役立つ部分をやってくださり,とても勉強になった

研修自体はまだ続きますが、今回得られたフィードバックをもとに、今後の研修の改善に活かしていきたいと考えています。

講義の風景①
講義の風景①
講義の風景①
講義の風景①

おわりに

今回の記事では、現在進行中の弊社で初めての実施となるエンジニア向け内定者研修についてご紹介いたしました。
内定者研修を通じて、今後入社するエンジニアのメンバーが入社後のオンボーディングをよりスムーズに進められるようにサポートすることができると考えております。 また、研修の企画・運営に携わった若手メンバーにとっても、 知識の整理や研修の主要メンバーとしてという新たなチャレンジの機会となり、貴重な成長の機会となっていると感じています。

今回の研修の経験を含めて、今後もエンジニアの成長を支援する取り組みを続けていきたいと考えています。

最後まで読んでいただき、ありがとうございました。

Go 1.24 の encoding/json の omitzero について

この記事は every Tech Blog Advent Calendar 2024 19 日目の記事です。

はじめに

こんにちは、@きょーです!普段はデリッシュキッチン開発部のバックエンド中心で業務をしています。

導入

Go 1.24 が来年の 2 月にリリースされます。 ドラフトではありますが Go 1.24 のリリースノートは既に公開されています(2024 年 12 月 19 日時点)。

tip.golang.org

encoding/jsonomitzeroという json タグが追加されomitemptyと何がどう違うのか気になったため、調べたことについて共有していこうと思います。

encoding/json とは

json のエンコードとデコードを実装しているパッケージになります。json と Go の値の対応付けを Marshall、Unmarshal によって行っています。

pkg.go.dev

サーバーからのレスポンスを json 形式にしてデータを返す際や、リクエストからデータを読み込む際に使うことが多いパッケージかと思います。

まずはomitzeroを理解するためにomitemptyの挙動とその問題点についてみていきます。

omitempty について

Go の構造体を json に変換する際に、フィールドの値がゼロ値の場合にそのフィールドを出力しないという便利な機能です。この機能を活用することで、json のサイズを削減したり、不要な情報を排除したりできます。

以下のように json タグにomitemptyとつければ機能します。

type User struct {
    ID        int       `json:"id,omitempty"`
    Name      string    `json:"name,omitempty"`
}

実際に空の構造体を用意して動かしてみましょう。全てのフィールドがゼロ値となり、何も出力されないことが期待されます。

func main() {
    u := User{}
    jsonData, _ := json.Marshal(u)
    fmt.Println(string(jsonData))
}

output は以下のようになり、省略してほしい値は出力されていないことが確認できました。

{}

しかしomitemptyには 2 つの課題がありました

課題1

プリミティブな値で構成された空の構造体に対して omitempty を指定するとフィールドが出力されてしまう点です。

例を見ていきましょう。

以下のような構造体で、先ほどと同じように実行してみます。

type User struct {
    ID           int          `json:"id,omitempty"`
    Name         string       `json:"name,omitempty"`
    SampleStruct SampleStruct `json:"sample_struct,omitempty"`
}

type SampleStruct struct {
    SampleField1 int `json:"sample_field_1,omitempty"`
    SampleField2 int `json:"sample_field_2,omitempty"`
}

output は以下のようになり、omitemptyを指定している構造体の値が空なので何も出力されないことを期待しますが、構造体のフィールド名が出力されてしまっています。

{ "sample_struct": {} }

課題2

課題 1 に繋がるところではありますが、構造体自体はその中身が空であっても omitempty はゼロ値とはみなさない点です。

これも例を見ていきましょう。

以下のような構造体で、先ほどと同じように実行してみます。

type User struct {
    ID        int       `json:"id,omitempty"`
    Name      string    `json:"name,omitempty"`
    CreatedAt time.Time `json:"created_at,omitempty"`
    UpdatedAt time.Time `json:"updated_at,omitempty"`
}

output は以下のようになりました。intstring などのプリミティブな値は期待通り出力されていませんが、構造体を指定した箇所は出力されてしまっています。

{
  "created_at": "0001-01-01T00:00:00Z",
  "updated_at": "0001-01-01T00:00:00Z"
}

これは Go の仕様で以下の値しかゼロ値を定められていないためです。

変数や各要素 ゼロ値
bool false
数値型 0
文字列 ""
ポインタ nil
関数 nil
インターフェース nil
スライス nil
チャンネル nil
マップ nil

tip.golang.org

上記のような悩みを解決できるものがomitzeroになります。

omitzero について

Go 1.24 から使える json タグの一つで、omitemptyと同様にフィールドに指定することで使えるようになります。

先ほどあげた課題が解決されるようになったので、確認していきます。

課題1に対して

プリミティブな値で構成された空の構造体も省略されるようになります。

以下のような構造体で、先ほどと同じように実行してみます。

type User struct {
...
    SampleStruct SampleStruct `json:"sample_struct,omitzero"`
}

type SampleStruct struct {
...
}

output は以下のようになり、期待している値になっていることが確認できました!

{}

課題2に対して

omitzeroオプションが追加されたフィールドの構造体に IsZero メソッド(帰り値は bool)がある場合はそのメソッドを用いてゼロ値かどうかを判定し、ゼロ値である場合はomitemptyと同様にエンコードから省略されるようなります。

以下のような構造体で、先ほどと同じように実行してみます。

type User struct {
...
    CreatedAt time.Time `json:"created_at,omitzero"`
    UpdatedAt time.Time `json:"updated_at,omitzero"`
}

output は以下のようになり、カスタムした値を初期に設定した構造体も省略されていることがわかります。

{}

これは time パッケージの Time 構造体にある IsZero メソッドがゼロ値チェックに使われ、ゼロ値であったために省略されるようになったことを示しています

// IsZero reports whether t represents the zero time instant,
// January 1, year 1, 00:00:00 UTC.
func (t Time) IsZero() bool {
    return t.sec() == 0 && t.nsec() == 0
}

pkg.go.dev

例として Time 構造体を使いましたが、以下のように構造体とそのメソッドである IsZero を用意することで自分たちのアプリケーションに合わせたゼロ値を定義できるようになります。

type User struct {
...
    SampleStruct SampleStruct `json:"sample_struct,omitzero"`
}

type SampleStruct struct {
...
}

func (s SampleStruct) IsZero() bool { // 何の値をゼロ値とするか決められるようになる
    return s.SampleField1 == 1 && s.SampleField2 == 1
}

func main() {
    u := User{}
    jsonData, _ := json.Marshal(u)
    fmt.Println(string(jsonData))
}

使う際は慎重に

ここまでゼロ値の省略について話してきましたが、使う際は慎重に使っていきましょう(omitempty もそうですが)。

例えばレコードごとの ID や作成日時などはサーバー側では一見不要に見えるかもしれませんが本当に不要かどうかは判断できません。 省略しても良いかどうかはアプリケーションごとのロジック(ゼロ値をそのまま使いたい場合もたくさんある)にもよりますし、フロントやクライアント側でどう使われているかを把握していなければ適切に使うことは難しい気がしています。

まとめ

以上 Go 1.24 でencoding/jsonに追加されるomitzeroオプションの説明でした。軽くまとめます。

  • omitempty
    • ゼロ値の場合、json 出力から省略する
  • omitzero
    • プリミティブな値で構成された空の構造体の場合はフィールド名も含めて省略する
    • 構造体にIsZeroメソッドが実装されている場合、そのメソッドの結果に基づいてゼロ値かどうかを判断し、ゼロ値であれば省略する

どちらを使うべきか

  • 構造体のゼロ値判定が必要な場合
    • omitzero
  • 構造体以外のゼロ値を判定したい場合
    • omitempty

注意点

  • 必須フィールドやビジネスロジック上重要なフィールドを誤って省略しないように注意が必要

最後に

Go 1.24 楽しみですね! 今回紹介したものはほんの一部ですので、気になった方はぜひリリースノート追ってみてください!

明日のアドベントカレンダーは 庄司(ktanonymous)さんによる 「エブリー初のエンジニア向け内定者研修を実施しています」 です!

参考

PS

みなさんは好きなゲームありますか?僕は最近 DAVE THE DIVER というゲームにハマっているのですが、永遠に時間が溶けててやばいです。ゲームのやりすぎで朝日を見る事も厭わない勇気有る方達、どうぞ一歩前へ。

store.steampowered.com

ISUCON 14感想戦

この記事は every Tech Blog Advent Calendar 2024の18日目の記事です。

はじめに

こんにちは、TIMELINE 開発部 Service Development をしているhondです!
今回は12/8に行われ、弊社がISUポンサーとして協賛したISUCON 14に会社の同期と友人と共に参加した際に行った事前準備と当日の流れ、反省をまとめていこうと思います。
本ブログ以外にもISUCONに向けて勉強したことISUCON14 に ISUポンサーの枠で出場しましたもアドベントカレンダーとして投稿されているのでぜひ読んでみてください!

事前準備

前提

今回はチームメンバー全員がGoの経験があることから言語はGo、ISUCON 12予選より他のDBだとしても使い慣れているMySQLに移行することが良いことを知っていたのでMySQLを使うことを前提に準備を行いました。

概要

事前準備としては主に下記の三つを行いました。

  1. 達人が教えるWebパフォーマンスチューニング 〜ISUCONから学ぶ高速化の実践の読解
  2. 過去問
  3. 競技に使うツール導入スクリプトの作成

達人が教えるWebパフォーマンスチューニング 〜ISUCONから学ぶ高速化の実践の読解

こちらの本はモニタリングや負荷試験、ログの集計をはじめとしたWebサービスのパフォーマンス改善を行う際に必要なメソッドがまとまったものになっています。

また、本番同様の環境が準備されたprivate-isuに対し、どのような改善を行えばスコアが上がるか丁寧に順序立てて説明されているのでISUCONに参加したことない人やWebサービスのパフォーマンス改善の概要を知りたい人にはおすすめの一冊です!

過去問

AWS環境で構築するものであればISUCON 5以降の一部予選、本戦の問題が公式にてAMIでの実行方法が公開されています。(ISUCON過去問)本番では例年EC2サーバーが三台用意されるので先ほどのAMIを元に三台起動すると本番同様の環境で過去問に着手することができます。

過去問を解いた後は一部の予選・本戦問題では公式から解説と講評ISUCON13 問題の解説と講評が出ているのでそちらを参考に答え合わせを行うとより理解が深まります。

ISUCON 13ではDNSが初登場するなどまだまだ進化し続けるISUCONなので過去問を解いて引き出しを増やしておくと良さそうです。

競技に使うツール導入スクリプトの作成

競技ではMySQLスロークエリーの解析やアクセスログの集計、APIサーバーのプロファイリングが必要になるので、それらを円滑に行うためのツールやcnfを事前にまとめておきました。

MySQLスロークエリーの解析

初期状態ではスロークエリーログの有効化や出力先が設定されていないのでmy.cnfに以下を記述します。

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/mysql-slow.log
long_query_time = 0

上記によって/var/log/mysql/mysql-slow.logにスロークエリーログ(0秒を閾値にしているので全てのクエリー)が出力されるようになっているので、それらを解析するためのツールとしてpt-query-digestを導入します。

pt-query-digestを用いることでそれぞれのクエリーが全体のリクエストタイムに締める割合やRow sentやRow examineを可視化することができます。

最後にこの状態ではスロークエリーログが同一ファイルに出力されベンチマークごとの結果を確認できないので、一時的に出力先を変更するためにpt-query-digestのラッパーのquery-digestを導入します。
下記のコマンドを実行することでquery-digestを実行することができます。

perl ./query-digester -duration 10

アクセスログの集計

基本的にISUCONではnginxを経由してAPIサーバーに到達するかたちになっているので、nginxのcnfを修正しJSON形式でログが出力されるようにします。

http {
    // 省略
    log_format json escape=json '{"time":"$time_iso8601",'
                                 '"host":"$remote_addr",'
                                 '"port":$remote_port,'
                                 '"method":"$request_method",'
                                 '"uri":"$request_uri",'
                                 '"status":"$status",'
                                 '"body_bytes":$body_bytes_sent,'
                                 '"referer":"$http_referer",'
                                 '"ua":"$http_user_agent",'
                                 '"request_time":"$request_time",'
                                 '"response_time":"$upstream_response_time"}';

    access_log /var/log/nginx/access.log json;
    //省略
}

次にアクセスログを集計するツールとしてalpを導入します。 alpはステータスコードやカウント数をはじめレスポンスタイムの最大・平均・最小値などのメトリクスでアクセスログを集計できるツールとなっています。

最後にMySQLのスロークエリーログ同様にベンチマークごとに結果を確認するために、アクセスログファイルをローテートするスクリプトを作成します。

#!/bin/sh

new_file_name=/var/log/nginx/access.log.`date +%Y%m%d-%H%M%S`

mv /var/log/nginx/access.log $new_file_name

nginx -s reopen

APIサーバーのプロファイリング

今回APIサーバーの言語はGoを選択しているので、プロファイリングツールとしてpprofを用います。
pprofの導入はとても簡単で、下記のようにmain.goに数行追加するだけでプロファイリングできるようになります!

func main() {
    // ここから
    runtime.SetBlockProfileRate(1)
    runtime.SetMutexProfileFraction(1)
    go func() {
        log.Fatal(http.ListenAndServe("localhost:6060", nil))
    }()
    // ここまでを追加する

    log.Fatal(http.ListenAndServe("localhost:8080", nil))
}

当日

ここからは当日の流れになります。

ツール導入スクリプトの実行 10:00 ~ 10:30

競技に使うツール導入スクリプトの作成にて作成したスクリプトを実行し計測可能な状態に、一部のコードをGithubに連携しdevelop branchにmergeしたらEC2にデプロイされる状態にしました。
その後初めてのベンチマークの実行を行いスコアの計測を行いました。
この時点でのスコアは700点程度。

10:30 ~ 13:00

計測の準備が完了したので実際にベンチマークを実行してその結果を確認していきました。

初期の実装ではMySQLのCPU使用率が175%付近になりAPIサーバーやnginxがうまく使えていない状態だったのでquery-digestを用いてスロークエリーログの確認を行いました。
スロークエリーの改善では主にquery-digestを用いてトータルレスポンスの割合が上位になっているクエリーの特定、EXPLAINを用いて実行計画の確認を行いクエリーの改善を行いました。
query-digestと実行計画の結果から上位のスロークエリーはテーブルにインデックスが不足していることでフィルタ処理される行の割合、調査される行の見積もりが悪化していることがわかったのでそれぞれのテーブルに対してインデックスの追加を行い改善を行いました。

オーナーに紐づく椅子を取得するクエリーに関してはサブクエリーを実行するなどクエリー自体の改善が必要そうだったので僕がインデックスの追加を行っている間にチームメイトに改善をお願いしました。

インデックスの追加とクエリーの改善によりスロークエリーは改善されお昼時点で3000点を超え一時80位台に到達しました!

14:00 ~ 16:00

スロークエリーの改善は完了していたので、マニュアルのスコアの計算とアクセスログの結果から配車と通知の改善が必要そうなことを確認し対象の箇所の改善に挑みました。
スコアの計算は下記のように示されていました。

以下に示す要素の合計がスコアとなります。

- 椅子がライドとマッチした位置から乗車位置までの移動距離の合計 * 0.1
- 椅子の乗車位置から目的地までの移動距離の合計
- ライド完了数 * 5

結果としては二時間ほどかけて改善に挑んだのですが、アプリケーションの理解不足でめぼしい改善ができずスコアとしては横ばいでした。

16:00 ~ 18:00

16:00以降は当初より予定していたAPIサーバーとDBのインスタンスを分離する作業に着手しました。

初期実装ではnginx, APIサーバー、DBは全て一つのインスタンスで完結していてスロークエリー改善後もMySQLがCPU使用率の大半を占めていたのでnginxとAPIサーバーのインスタンス、DBのインスタンスと二台構成にする対応を開始しました。
作業としてはAPIサーバーの向き先DBのホストの修正とMySQLでbind-addressを追加するのみだったので練習で行った通りに作業を完了しベンチマークでスコアを測定しました。

CPU負荷の大半を占めていたMySQLが分離したことでAPIサーバーで使えるCPUが増えベンチマークのログを見るとスコアが8000点を超えるなど順調に思われましたが下記のクリティカルエラーが発生ベンチマークが失敗する状態になってしまいました。

msg=クリティカルエラーが発生しました error="椅子に想定していないライドの状態遷移の通知がありました (CODE=12): ride_id: 01JEJMQWN1HEGJM5NZQ40A6KG2, expect: MATCHING, got: COMPLETED"

クリティカルエラーの内容によると15:00まで改善に着手していた通知の不整合とのことだったのでチームメイトとペアプロで改善を試みましたが、対象のクリティカルエラーは改善することはできず複数台構成を諦めることになりました。

後日同僚にクリティカルエラーについて話したところそのチームでも同様の現象が見られ、初期実装では通知間隔が短く複数台構成にしてパフォーマンスが向上することで不整合が発生するので通知間隔を延ばせば改善できたとのことでした。
通知間隔をどこまで延ばして良いかなどは当日マニュアルの猶予時間に記述されていました。

結果

結果スコアの推移は下記画像のようになりました。

インデックスやクエリーの修正によるスロークエリーの改善を行った14:00付近以降はめぼしい改善ができていないので約四時間スコアが横ばいのまま競技終了を迎えました。
しかし、5.環境チェックNGで失格になりました😭
おそらく原因としては僕が複数台構成にするときにAPIサーバーをdisableにしたような気が。

まとめ

僕自身3回目のISUCON参加となるのですが、今まではろくに準備を行わず参加していたのでそれまでに比べれば入念に準備を行えたため当日は納得のいく動きをできたと感じました(結果としては失格ですが笑)。

複数台構成にした時にベンチマークでクリティカルエラーが発生した通知機能に関してはヒントとなる猶予時間が、当日のマニュアルに記述されていたので改めてマニュアルを確認することは大事だと感じました。
また、ペアプロを行うときにアプリの仕様について確認し合う場面が多くあったので、チームで時間を取りマニュアルの読み合わせを行う時間を取ることでその後の実装で共通認識を持って作業できるのではないかと思いました。

失敗の原因になった環境チェックに関して、当日マニュアルの競技環境の確認に環境チェックを行うコマンドが明記されています。
今回はこのチェックを行うことを怠り終了間際までGoのコードと向き合っていたので、普段の過去問を行う際や次回本番では環境確認時にエラーが発生することがあることも踏まえ終了時間の30分以上前には環境確認を含めた締め作業を行おうと思います。

来年はより高スコアを狙えるように普段の業務からパフォーマンスの改善を行えるところがないかなど意識していきます。

PageSpeed Insightsを触ってみる

この記事は every Tech Blog Advent Calendar 2024の17日目の記事です。

はじめに

エブリーでデリッシュキッチンの開発をしている本丸です。
恥ずかしながら今までWebのパフォーマンスの調査をしたことがなかったのですが、直近で触れる機会があったため、どのように調査したのか簡単にではありますが説明させて頂こうかと思います。

背景

デリッシュキッチンでSEO対策を行う中で、別のエンジニアの方からPageSpeed Insightsを使ってパフォーマンスの改善を行なってはどうかという話が上がりました。
PageSpeed Insightsについてあまりよくわかっていなかったため調査するところから開始しました。(パフォーマンスでページのランキングが上がるという記述は公式のドキュメントからは見つけられておりませんので、確実にページのランキングに効くという内容ではないことはご認識いただければと思います。)

PageSpeed Insights

Google DeveloperのPageSpeed Insights API についてによれば、PageSpeed Insightsとは下記のことができるツールとされています。執筆時点(2024/12/16)では日本語のページと英語のページに差分があるので英語ページを参照していただく方が良いかもしれません。

PageSpeed Insights では、モバイル端末やパソコン向けのページの実際のパフォーマンスに関するレポートと、そうしたページの改善方法を確認できます。

PageSpeed Insightsでは、実際のユーザーの情報の統計からのスコアとLighthouseを使用したシミュレーション環境のスコアを出力してくれます。

Lighthouse

chrome for developersのLighthouse の概要によると、Lighthouseは下記のことができるツールとされています。

Lighthouse は、ウェブページの品質を改善するためのオープンソースの自動化ツールです。公開されているウェブページでも、認証が必要なウェブページでも実行できます。パフォーマンス、ユーザー補助、プログレッシブ ウェブアプリ、SEO などの監査が行われます。

LighthouseではCPUやネットワーク環境を指定することができ、指定したシミュレーション環境でのパフォーマンスを確認することができます。また、パフォーマンスのスコアが低いものに関してどのような改善方法があるのかを教えてくれます。

話の本筋と外れますが、Chromeの開発者ツールなどからPageSpeed Insightsの一機能としてではなくLighthouse単体として使用することもできます。 公開されているものであればPageSpeed Insightsを使用しても良いのですが、ローカルや開発環境など外部に公開していない環境でパフォーマンスを確認したいときにはLighthouseをChromeの開発者ツールから使うのが便利そうです。

デリッシュキッチンをPageSpeed Insightsで確認

デリッシュキッチンをPageSpeed Insightsで確認すると実際のユーザー情報の統計からのスコアは次のようになっていました。

こちらのスコアでは各指標でユーザーごとに良好・改善が必要・不良の3つのどれかで判定され、その75パーセンタイルが最終的な結果として出力されます。 各指標が何を表しているのかを下記にまとめます。

  • Largest Contentful Paint (LCP)
    • ユーザーがページにアクセスしてから、表示領域内で最も大きなコンテンツが表示されるまでの時間
  • Interaction to Next Paint (INP)
    • ユーザーがページ内で行うクリックなどの操作の応答性の指標
  • Cumulative Layout Shift (CLS)
    • ユーザーが予期しないレイアウトの変更がどの程度発生したかの指標
  • First Contentful Paint (FCP)
    • ユーザーがページにアクセスしてから最初のコンテンツが描画されるまでの時間
  • Time to First Byte (TTFB)
    • リソースをリクエストしてから最初のデータが返ってくるまでの時間

デリッシュキッチンのスマホ表示では全ての指標で良好を示しているので、実際にデリッシュキッチンを使用しているほとんどのユーザーの環境ではパフォーマンスが問題ないと言えるかと思います。

シミュレーション環境に関しては次のようになっていました。

パフォーマンス、ユーザー補助、おすすめの方法、SEOの4つの項目があるのですが、今回はパフォーマンスに注目していこうかと思います。 パフォーマンスでは次の5つの指標を確認することができます。

  • First Contentful Paint (FCP)
    • 最初にコンテンツが描画されるまでにかかった時間
  • Largest Contentful Paint (LCP)
    • 表示領域内で最大のコンテンツが表示されるまでにかかった時間
  • Total Blocking Time (TBT)
    • コンテンツの最初の描画から、50ms以上かかったタスクの処理時間の合計
  • Cumulative Layout Shift (CLS)
    • ブラウザの表示領域内で意図しないレイアウトの変更がどの程度あったかの指標
  • Speed Index (SI)
    • ページのロード中にコンテンツがどれだけ早く視覚的に表示されるか

残念ながらデリッシュキッチンは、CLSの指標以外のスコアが全体的に低いようです。
PageSpeed Insights(Lighthouseでも同様)ではシミュレーション環境で見つかった問題をどのように修正すれば良いかの方針も示してくれます。 例えば、TBTのスコアに悪影響を及ぼしているメインスレッドの処理に関する問題がある場合は図のように方針を示してくれます。

Webのパフォーマンス改善に向けて

ここからは少し話が変わりますが、PageSpeed InsightsでTBTの指標が悪いことがわかったのでもう少しだけ詳細に見ていこうかと思います。
Chromeの開発者ツールの中にパフォーマンスの項目があります。 このパフォーマンスを確認してみると次のような結果になりました。(ボトルネックがわかりやすいようにCPUとNetworkの品質を落としています。)

画像のうち、赤枠で囲った箇所がメインスレッドのパフォーマンスを表している箇所で、その中で赤で表示されているものが50ミリ秒以上かかっていてTBTのスコアに悪影響を与えているものになります。 この次に、何の処理がパフォーマンスに悪影響を与えているかの確認などをしていくことになるかと思うのですが、本記事では概要をつかむところまでということでここまでにしておこうかと思います。

まとめ

PageSpeed Insightsを使って、実際にデリッシュキッチンのパフォーマンスを見てみましたが、改善の余地がたくさんあることがわかりました。
現段階では、パフォーマンスに関する調査を行い、改善の方針を立てるというところまでしかできておりません。来年から実際にパフォーマンスの改善に向けて動く予定ですので、実際に改善を進める中で何かお伝えできる点があればまた共有させていただければと思います。