はじめに
リリース直後の動作確認で、
「SQLログが1行も出ていない。処理が正常終了していないかも」
と一瞬パニックになった経験をまとめます。
ただ、よく考えるとエラーログは出ていなかったので、
致命的な失敗ではなく、処理自体はおおむね正常に流れていた可能性が高い状態でした。
結論はシンプルで、
本番だけログレベルが違っていただけでした。
同じように焦る人を減らすために、何が起きていたか整理します。
この記事で得られることは次の3点です。
- 環境ごとのログレベル差分で起こる典型的なハマり方
- GORM のログレベル挙動（通常SQLとスロークエリ）
- 本番で SQL ログに頼りすぎないための、最低限のログ設計
何が起きたのか
本番環境では、アプリ側のログレベルが INFO から WARN に設定されていたため、
SQL のうちスロークエリだけが WARN レベルで出力され、
通常クエリ（SELECT / INSERT / UPDATE）が一切ログに出ていませんでした。
環境ごとの差分は次のとおりです。
- ローカル: INFO（SQLが全て出る）
- QA: INFO（SQLが全て出る）
- 本番: WARN（スロークエリのみ出る）
つまり、アプリもDBも正常で、設定差分だけが原因でした。
なぜ焦ったのか
- SQL が出ないと「何か動いていないのでは」と感じやすい
- バッチやAPIの動作確認では SQL ログが安心材料になりがち
- 本番だけ静かだと「壊したかもしれない」と錯覚する
特にスロークエリだけ出る構成だと、
「通常SQLは出ないのに、スロークエリだけ急に出る」
という挙動になり混乱しやすいです。
スロークエリだけ出た理由
GORM のログ出力は、イベント種別ごとにおおむね次のレベルで扱われます。
- 通常の SQL は Info レベル
- スロークエリは Warn レベル
- エラーは Error レベル
としてログが出力されます。
そのため、ログレベルが Warn 以上になっていると、
通常の SQL が表示されず、スロークエリだけが見える状態になります。
ここでいうスロークエリは、実行時間がしきい値を超えたSQLのことです。
GORM では SlowThreshold でしきい値を決められ、たとえば 500ms に設定した場合は 500ms を超えたクエリが対象になります。
スロークエリログは、次のような原因の切り分けに使えます。
- インデックス不足でフルスキャンになっている
- N+1 のようにクエリ回数が過剰になっている
- 一時的なDB負荷で応答が遅くなっている
本番で通常SQLを抑える構成でも、スロークエリだけは残す運用にしておくと、性能劣化の初期兆候を拾いやすくなります。
なぜ本番だけ WARN にしていたのか
本番だけ WARN にする判断自体は珍しくありません。理由は次のようなものです。
- ログ量を抑えて保管コストを下げたい
- I/Oを減らして性能影響を抑えたい
- 監視ではまずスロークエリや異常系を優先して見たい
今回のポイントは、この設計判断自体よりも「副作用を把握していなかった」ことでした。
シンプルな対策
同じミスを避けるためのポイントです。
1. 環境ごとのログレベルを明文化する
- config ファイル
- README
- インフラ側のパラメータ
などに、環境とログレベルの対応表を書いておく
2. 重要ログだけは常に INFO で出す
- アプリ起動
- バッチ開始/終了
- 処理件数
これらを INFO で出しておくと、SQL が静かでも安心して確認できます
例えば、次のようなキーと値で出しておくと確認がしやすくなります。
batch=start job=aggregate_salesbatch=finish job=aggregate_sales processed=1234 errors=0 duration_ms=8421
3. ログレベル差分はチェックリスト化する
リリースチェック項目に
「本番のログレベル確認」
を1つ入れておくと事故が減ります。
Go + GORM のログ設定サンプル
package db
import (
"log"
"os"
"time"
"gorm.io/driver/mysql"
"gorm.io/gorm"
gormlogger "gorm.io/gorm/logger"
)
func NewDB(dsn string) (*gorm.DB, error) {
appEnv := os.Getenv("APP_ENV") // local / qa / prod
logLevel := gormlogger.Info
if appEnv == "prod" {
logLevel = gormlogger.Warn
}
newLogger := gormlogger.New(
log.New(os.Stdout, "\r\n", log.LstdFlags),
gormlogger.Config{
SlowThreshold: 500 * time.Millisecond,
LogLevel: logLevel,
IgnoreRecordNotFoundError: true,
Colorful: false,
},
)
return gorm.Open(mysql.Open(dsn), &gorm.Config{
Logger: newLogger,
})
}
この例だと、APP_ENV=prod のときは通常SQLは出さず、スロークエリ中心の出力になります。
逆に local や qa では Info で全SQLが見えるため、動作確認しやすくなります。
ドライバは MySQL を例にしていますが、ログレベルの考え方は PostgreSQL などでも同様です。
まとめ
本番で SQL ログが出なくても、
まずはログレベルを疑うのが近道です。
- DBエラー
- 接続不良
- デプロイミス
…といった深刻な問題ではなく、
単なる設定差分であることはよくあります。
心臓に悪いですが、落ち着いてログレベルを確認しましょう。