UTC で書いたログを日本時間の日付で grep したら、行のあった40日のうち35日で件数がずれた — 自作サーバの386行で数えた

自作の Node.js サーバが、拒否した要求を1行ずつログに書いています。行の先頭は new Date().toISOString() で、つまり UTC です。

[2026-10-02T16:29:00.000Z] BAD-KEY ...

ある日の昼、『今日(日本時間 10/3)はこのログに何行あるか』を知りたくて、こう数えました。

grep -c 2026-10-03 security.log

自作の集計画面は、その日について『テスト用でない接続元の行が1行ある』と出していました。grep で見えたのは自分で入れたテスト用の1行だけだったので、私は『集計の道具がテスト用の行を数えている』と疑いました。**翌日、道具は正しく、誤っていたのは私の grep のほうだと分かりました。**ログの 2026-10-03 は UTC の日付で、日本時間の 10/3 の 0:00〜8:59 の行は 2026-10-02 と書かれています。画面が数えていた1行は、日本時間 10/3 の 1:29 に来た要求で、ログには上のように 2026-10-02T16:29 と書かれていました。

当たり前の話ですが、実物でどれだけずれるかを数えたことがなかったので、数えました。

測ったもの

• 自作サーバのログ 1本。2026-10-06 00:00(日本時間)より前の 386行(2026-08-05〜2026-10-05)
• 1行ごとに、先頭の UTC 時刻を日本時間の日付に直し、日本時間で行のあった日ごとに(期間は62日ありますが、行のあった日は40日です)
  • 正しい件数(日本時間でその日に入る行)
  • grep の件数(その日付の文字列を含む行。grep -c 日付 と同じ判定)
  • 見落とし(その日に入るのに grep に出ない行)と 余分(grep に出るのにその日ではない行)
• 環境: Windows 11 / Node v24.18.1

結果

	実測
数えた日(日本時間で行のあった日)	40日
件数か中身がずれた日	35日
見落とし(合計)	83行
余分(合計)	82行

ずれ方の例です。

日本時間の日付	正しい件数	grep の件数	見落とし	余分
2026-08-05	8	25	0	17
2026-08-06	51	39	17	5
2026-09-25	12	22	1	11
2026-09-26	14	4	11	1
2026-10-03	6	4	3	1
2026-09-07	12	12	3	3
2026-10-04	4	4	1	1

下の2行がいちばん厄介でした。**件数は一致しているのに、数えている行が違います。**見落とした行と、隣の日から紛れ込んだ行が同じ数だっただけです。この形の日は 40日のうち 4日あり、表に載せたのはそのうちの2日です。件数だけ見比べて『合っている』と読むと、この4日は通ってしまいます。

見落とした行は、たいてい前の日の grep に余分として出ます(日本時間の 0:00〜8:59 は UTC では前日の 15:00〜23:59 だからです)。見落とし 83 と余分 82 が1行だけ違うのは、ある日の見落とし1行の UTC の日付(2026-08-28)が、日本時間では1行も無い日だったためです。この差はどこで切るかでも変わります(切り口より後の行は数えていません)。

裏返すと、日本時間では行が1行も無いのに、grep だけが当たる日があります。このログでは 2026-08-28 の1日で、正しい件数は0、grep -c 2026-08-28 は1です。上の40日はこの日を入れていません。入れると 41日のうち36日がずれ、見落とし83・余分83になります。

ずれが0だった5日は、その日の行がすべて日本時間 9:00〜23:59 に収まり、しかも翌日の 0:00〜8:59 に行が無かった日です(見落とし0・余分0の定義を言い直しただけですが、5日とも元のログで確かめました)。ずれないのは数え方が正しいからではなく、その日の行の時刻がそう並んでいたからです。なぜそう並んだのかは調べていません。

直し方: 読むときに日本時間へ直してから日付を取る

ログの書き方は変えていません(UTC で書くこと自体は正しいと考えています)。読む側で直します。下のスクリプトでは2通りの書き方で直し、食い違ったら数えずに止めるようにしました。

const jstByOffset = (t) => new Date(t + 9 * 3600 * 1000).toISOString().slice(0, 10);
const jstByIntl = (t) => new Date(t).toLocaleDateString("sv-SE", { timeZone: "Asia/Tokyo" });

• 上は 9時間足してから UTC の日付を取る書き方です。日本は夏時間が無いので成り立ちますが、夏時間のある地域ではそのまま使えません
• 下は Intl にタイムゾーンを渡す書き方です。sv-SE は YYYY-MM-DD の形で日付を返すロケールなので使っています。Node v24.18.1 では 386行すべてで上と同じ日付を返しました(食い違いは0行)。他の版・ICU の入っていないビルドでは確かめていません

grep で済ませたいときは、日本時間の 1日を UTC の範囲(前日 15:00 以上、当日 15:00 未満)に直して範囲で切る必要があります。日付の文字列1つでは切れません。

再現スクリプト(全文)

依存は0で、ファイルは読むだけです。行の中身は1文字も出しません(IP などが入っているログに当てても、出るのは日ごとの件数と日付だけです)。引数なしなら、境界をまたぐ作り物の8行で試します。--until は時差つきでしか受け付けません。日付だけの 2026-10-06 は UTC の 0 時(日本時間 9:00)と解釈されるので、この記事の取り違えをスクリプト自身が起こすからです。ファイル名の書き忘れ・読めないファイル・時刻を読めた行が0行のときも、数えずに終了コード1で止まります。

// repro-utc-grep.mjs — UTC で時刻を書いたログを、ローカル(日本時間)の日付で grep すると何行ずれるかを数える。
// 依存0・読み取りのみ。行の中身(IPなど)は1文字も出さない。出すのは日付と、日ごとの件数だけ。
//
//   node repro-utc-grep.mjs                      作り物の8行で試す(ファイルを読まない)
//   node repro-utc-grep.mjs --file app.log       実物のログで数える
//   node repro-utc-grep.mjs --file app.log --until 2026-10-06T00:00:00+09:00 --json
//   (--until は時差つきで渡す。日付だけの『2026-10-06』は UTC の 0 時と解釈されるので受け付けない)
//
// 行の先頭が [2026-10-03T16:29:00.000Z] の形(Date#toISOString)であることを前提にしている。
import { readFileSync } from "node:fs";

const args = process.argv.slice(2);
const opt = (k) => { const i = args.indexOf(k); return i >= 0 ? args[i + 1] : null; };
const file = opt("--file");
const untilArg = opt("--until");
const until = untilArg ? Date.parse(untilArg) : null;
const asJson = args.includes("--json");
const stop = (msg) => { console.error(msg); process.exit(1); };

// 値の無い --file や、読めない --until を黙って見過ごさない
// (見過ごすと、作り物で数えた結果や、切らずに数えた結果が、正常に終わったように見える)
if (args.includes("--file") && (!file || file.startsWith("--"))) stop("--file の後にファイル名がありません");
// 日付だけの値は UTC の 0 時(日本時間なら 9:00)と解釈される。この道具が数えている取り違えそのものなので受け付けない
const hasOffset = /T\d{2}:\d{2}.*(Z|[+-]\d{2}:\d{2})$/;
if (args.includes("--until") && (!untilArg || !hasOffset.test(untilArg) || Number.isNaN(until))) {
  stop("--until は時差つきで渡してください(例: 2026-10-06T00:00:00+09:00)");
}

const SAMPLE = [
  "[2026-10-02T14:59:59.000Z] A", // 日本時間 10/02 23:59
  "[2026-10-02T15:00:00.000Z] B", // 日本時間 10/03 00:00
  "[2026-10-02T23:59:59.000Z] C", // 日本時間 10/03 08:59
  "[2026-10-03T00:00:00.000Z] D", // 日本時間 10/03 09:00
  "[2026-10-03T14:59:59.000Z] E", // 日本時間 10/03 23:59
  "[2026-10-03T15:00:00.000Z] F", // 日本時間 10/04 00:00
  "[2026-10-03T20:00:00.000Z] G", // 日本時間 10/04 05:00
  "no timestamp line",
];

let text = "";
if (file) {
  try { text = readFileSync(file, "utf8"); } catch (e) { stop(`ファイルを読めませんでした: ${e.code || e.message}`); }
}
const lines = file ? text.split(/\r?\n/).filter((l) => l.length) : SAMPLE;

// 変換を2通り書き、食い違ったら止める(片方の書き方の誤りを、もう片方で見つけるため)
const jstByOffset = (t) => new Date(t + 9 * 3600 * 1000).toISOString().slice(0, 10);
const jstByIntl = (t) => new Date(t).toLocaleDateString("sv-SE", { timeZone: "Asia/Tokyo" });

let unreadable = 0, cut = 0, disagree = 0;
const rows = [];
for (const l of lines) {
  const m = /^\[(\d{4}-\d{2}-\d{2}T[^\]]+Z)\]/.exec(l);
  const t = m ? Date.parse(m[1]) : NaN;
  if (Number.isNaN(t)) { unreadable++; continue; }
  if (until !== null && t >= until) { cut++; continue; }
  const a = jstByOffset(t), b = jstByIntl(t);
  if (a !== b) disagree++;
  rows.push({ jst: a, utc: m[1].slice(0, 10), text: l });
}
if (disagree) stop(`変換が ${disagree} 行で食い違いました。数えません`);
if (!rows.length) stop(`時刻を読めた行が0行です(読めない行 ${unreadable} / 切った行 ${cut})。数えません`);

// 数えるのは『日本時間で行のある日』。その日ごとに、正しい件数と grep の件数を比べる
const days = [...new Set(rows.map((r) => r.jst))].sort();
const perDay = days.map((d) => {
  const jst = rows.filter((r) => r.jst === d).length;
  const grep = rows.filter((r) => r.text.includes(d)).length; // 素朴な grep d と同じ判定
  const both = rows.filter((r) => r.jst === d && r.text.includes(d)).length;
  return { day: d, jst, grep, missed: jst - both, extra: grep - both };
});
// 日本時間では行が無いのに、UTC の日付としてだけ現れる日(上の表には入らない。grep するとここにも行が出る)
const grepOnly = [...new Set(rows.map((r) => r.utc))].filter((d) => !days.includes(d)).sort()
  .map((d) => ({ day: d, grep: rows.filter((r) => r.text.includes(d)).length }));
const sum = (k) => perDay.reduce((s, r) => s + r[k], 0);
const out = {
  source: file ? "file" : "sample",
  until: until === null ? null : new Date(until).toISOString(),
  lines: lines.length, unreadable, cutAfterUntil: cut, counted: rows.length,
  days: perDay.length,
  daysWithMismatch: perDay.filter((r) => r.missed || r.extra).length,
  missedTotal: sum("missed"), extraTotal: sum("extra"),
  perDay,
  grepOnly,
};
if (asJson) { console.log(JSON.stringify(out, null, 2)); process.exit(0); }
console.log(`入力: ${file ? "ファイル" : "作り物の8行"}`);
console.log(`読んだ行 ${out.lines} / 時刻が読めない行 ${unreadable} / 切った行 ${cut} / 数えた行 ${rows.length}`);
console.log("日本時間の日付 | 正しい件数 | grep の件数 | 見落とし | 余分");
for (const r of perDay) console.log(`${r.day} | ${r.jst} | ${r.grep} | ${r.missed} | ${r.extra}`);
console.log(`食い違った日 ${out.daysWithMismatch} / ${out.days} 日・見落とし計 ${out.missedTotal} 行・余分計 ${out.extraTotal} 行`);
console.log(`日本時間では行が無いのに grep だけが当たる日: ${grepOnly.length ? grepOnly.map((g) => `${g.day}(grep ${g.grep})`).join(" / ") : "なし"}`);

引数なしで走らせた結果です(作り物の8行)。

入力: 作り物の8行
読んだ行 8 / 時刻が読めない行 1 / 切った行 0 / 数えた行 7
日本時間の日付 | 正しい件数 | grep の件数 | 見落とし | 余分
2026-10-02 | 1 | 3 | 0 | 2
2026-10-03 | 4 | 4 | 2 | 2
2026-10-04 | 2 | 0 | 2 | 0
食い違った日 3 / 3 日・見落とし計 4 行・余分計 4 行
日本時間では行が無いのに grep だけが当たる日: なし

測っていないこと

• 測ったのは自分のサーバのログ 1本だけです。35/40 という割合は、行の時刻の偏り方で変わります。一般的な割合ではありません
• 先頭が [...Z] の形の行しか読みません。他の形の時刻は数えていません(読めない行は件数として出します)
• grep そのものは走らせていません。スクリプトは『その日付の文字列を含むか』で判定しており、grep -c 日付 と同じ判定のつもりですが、grep を実際に走らせて突き合わせてはいません。時刻を読めなかった行と切り口より後の行は、grep の列にも入れていないので、ファイル全体への grep -c とは一致しないことがあります
• 最後の日(2026-10-05)の数は切り口の時点のものです。いまのログに grep すると値が変わります
• 夏時間のあるタイムゾーンでは試していません

やめたこと

• UTC で書いたログを、ローカルの日付の文字列で grep して件数を数えること。
• 件数が一致したことを、同じ行を数えた証拠として読むこと。

---

Windows で AI や定期処理を無人で走らせている方向けに、タスク スケジューラの設定を読み取りだけで点検する診断スクリプトを置いています。