🙇‍♂️

Next.js初心者がLogを出すまでに苦労した話

2023/08/18に公開

何がしたかったのか

pinojs/pinoを使って、Next.jsのAPIを叩いた時に表示されるログを、CloudWatch Logsで確認したい。

前提条件

  • 筆者は、Next.js初心者(間違っていることは指摘お願いします!)
  • pinoは yarn add pinoでインストール済
    • ローカル環境では、問題なくログは出ている
  • アプリケーションは、AWS ECS Fargateにデプロイされている
    • ECSのタスク定義にてawslogsの設定は実施済み
    • CloudWatch Logsのロググループも作成済

実装

ロガーインスタンス

/lib/logger.ts
import { pino } from 'pino';

export const logger = pino({
  level: process.env.NODE_ENV !== 'production' ? 'debug' : 'info',
});

API (url: /api/health-check)

/src/app/api/health-check/route.ts
import { NextResponse } from 'next/server';
import { logger } from '@/lib/logger';

export function GET() {
  logger.info('info');
  logger.warn('warn');
  logger.error('error');
  logger.fatal('fatal');
  return NextResponse.json({ message: 'ok' });
}

しかし、上記のAPIをいくら叩いてもログが出てこない....

原因

ログを仕込んだAPIが、next buildを実行した時に静的なHTMLとしてレンダリングされていた。

Route (app)                                Size     First Load JS
┌ ○ /                                      82.5 kB         161 kB
└  ○ /api/health-check                      0 B                0 B
Route (pages)                              Size     First Load JS
─ ○ /404                                   182 B          76.5 kB
+ First Load JS shared by all              76.3 kB
  ├ chunks/framework-3d1e9be70c3da.js   45.1 kB
  ├ chunks/main-f4d50592e90a51.js        29.4 kB
  ├ chunks/pages/_app-529524f99094ab.js  195 B
  └ chunks/webpack-9eacbfc3ea00.js     1.67 kB

λ  (Server)  server-side renders at runtime (uses getInitialProps or getServerSideProps)(Static)  automatically rendered as static HTML (uses no initial props)

この部分に注目してください。

└  ○ /api/health-check                      0 B                0 B

○  (Static)  automatically rendered as static HTML (uses no initial props)

/api/health-checkの左に「⚪︎」が記載されています。
これは、このAPIがビルド時に自動的に静的HTMLとしてレンダリングされたことを示しています。


Next.jsでは、ビルド時に各ファイルに getServerSideProps or getInitialPropsが含まれているかどうかを確認します。

  • 含まれている場合
    • サーバーサイドにてアクセスされる度にHTMLをレンダリングする(Server-side Rendering)
    • JSファイルのままなので、logger.info()が実行されてログが表示される
  • 含まれていない場合
    • 事前に静的HTMLファイルを作成して、アクセスされる度にそのHTMLを返します
    • HTMLファイルではJSは動かないので、logger.info()は実行されず、ログも出ない

https://nextjs.org/docs/pages/building-your-application/rendering/automatic-static-optimization

https://zenn.dev/unreact/articles/nextjs-advanced-automatic-static-optimization-jp

解決策

解決策は非常にシンプルです。
Server-side RenderingのAPIにログを仕込めばOKでした。

今回は、検証のためapi/health-checkgetServerSidePropsを仕込んで、無理やりServer-side Renderingさせるようにしました。

├ λ /api/health-check  

λ  (Server)  server-side renders at runtime (uses getInitialProps or getServerSideProps)

上記の状態で、APIを叩いてみると、無事CloudWatch Logsにログが表示されました🙌🎉

あとがき

今回は、next build時の挙動をちゃんと理解できていなかったのが最大の敗因です。
そのせいで、実はpinoのライブラリのバグなんじゃない? とか AWS ECSのタスク定義ちゃんとできないんじゃないの?などなど、 色々な方、ものに濡れ衣を着せまくってました。。
しかし、悪いのは私でした。。
こういう動作するべきものが動作しない時は、今までの経験上98%自分が悪いので、これからもそれを意識しながら開発続けていきます。

マジで、CloudWatchにログが出た時は、嬉しすぎて結構大きい声出ました。。。(リモートワークでよかった)

Discussion