Macをスリープさせたらlaunchdの定時処理はいつ動くのか|16時間ずれた実行時刻の正体

Macをスリープさせたらlaunchdの定時処理はいつ動くのか|16時間ずれた実行時刻の正体 定期実行と通知

毎週月曜の朝8時に動くはずの処理が、その日の記録に1行もありませんでした。壊れたのかと思ってログを開いたら、ちゃんと動いた記録がありました。翌日の午前0時ちょうどに。

結論を先に書きます。予定時刻にMacが寝ていると、その回は「飛ぶ」のではなく「遅れる」。Macが起きたあとに、過ぎてしまった予定として実行されます。だからログに残る時刻は、自分が設定した時刻とはまったく違う数字になります。うちの実例では16時間ずれました。

私は清掃業を経営していて、プログラマーではありません。この記事は、うちのMacで実際に起きたことを、実物のログと設定ファイルを見ながら書いています。

月曜8時の処理が、火曜0時に動いていた

うちには週に1回だけ動かしている点検の処理があります。設定(plist)にはこう書いてあります。

<key>StartCalendarInterval</key>
<dict><key>Weekday</key><integer>1</integer><key>Hour</key><integer>8</integer><key>Minute</key><integer>0</integer></dict>

Weekday の 1 は月曜、Hour の 8 は8時です。つまり「毎週月曜の朝8時ちょうど」。この処理が自分で残している実行ログが、これです。

[2026-08-19 08:31] 停滞チェックを実行 → 停滞チェック_2026-08-19.txt
[2026-08-25 00:00] 停滞チェックを実行 → 停滞チェック_2026-08-25.txt
[2026-08-31 08:00] 停滞チェックを実行 → 停滞チェック_2026-08-31.txt
[2026-09-07 08:00] 停滞チェックを実行 → 停滞チェック_2026-09-07.txt

1行目の8月19日は水曜で、設定を入れた日に手で1回動かしたものです。3行目の8月31日と4行目の9月7日は、どちらも月曜で時刻もぴったり8時00分。設定どおりに動いています。

問題は2行目です。2026年8月24日が月曜でした。その日の8時の記録はどこにもありません。代わりに、翌日8月25日の午前0時00分に1回だけ動いています。予定より16時間遅れです。

大事なのは、飛ばされたわけではないという点です。月曜の予定はMacの中に残っていて、動ける状態になった時点で実行されました。「動かなかった」ではなく「遅れて動いた」。ここを取り違えると、原因の探し方が丸ごとずれます。

正直に書いておくと、このとき何日ぶんの予定が溜まっていたのかまでは確かめられていません。うちで確認できたのは「1回ぶんが遅れて1回動いた」ことだけです。何日も続けて寝かせたらどうなるかは試していないので書けません。

遅れて動くと、こういう副作用が出る

1. 日付が1日ずれる

この処理は、出力ファイルの名前を実行した日から作っています。

OUT="$AI_HOME/logs/停滞チェック_$(date '+%Y-%m-%d').txt"

date は「いま何日か」を返します。月曜に動けば 停滞チェック_2026-08-24.txt ができるはずでした。実際にできたのは 停滞チェック_2026-08-25.txt です。中身も、火曜日時点の状態として集計されています。

点検の処理なので実害はありませんでしたが、これが売上の集計だったら話が違います。「先月ぶんを締める」「昨日ぶんを集計する」といった処理を、実行した日から逆算して決めている場合、遅れた瞬間に対象がずれます。月初1日の深夜に動くはずの月次集計が2日にずれたくらいなら気づけますが、月末最終日の処理が翌月1日にずれると、集計する月そのものが変わってしまいます。

2. 見張りの仕組みが「動いていない」と誤判定する

うちには毎日13時に「今日の自動化がひととおり動いたか」を確かめる見張りの処理があります。判定は、その日の日付で成功の記録があるかどうかで見ています。

grep '^\[$KYOU' '$M/自動公開ログ.txt' | grep '✔' | tail -1

$KYOU は今日の日付です。つまり前日ぶんが今日の0時に遅れて動くと、前日は「動いていない」、今日は「動いた」と表示されます。どちらも事実ではありますが、人が見て意味を取り違えやすい形です。

ちなみに今回ずれた週1回の処理は、この見張りの対象に入れていませんでした。見張りが見ているのは毎日動く6件だけです。だから当時は誰も気づかず、後からログを読み返して分かりました。

うちがやったこと:定時処理を全部昼間に寄せた

対策は単純です。Macが確実に起きている時間帯に、予定時刻を動かしました。

いまうちのMacには16個の自動処理が登録してあります。そのうち時刻を決めて動かしているのは13個で、設定されている時刻はこうなっています。

時刻 中身 頻度
06:30 記事のネタを補充する 毎日
07:00 記事を1本公開する 毎日
07:00 記事候補を補充する(別サイト) 毎週月曜
07:30 その日の予定をLINEに送る 毎日
08:00 記事を1本書く(別サイト) 毎日
08:00 週次の点検・週次の報告(3件) 毎週月曜
08:00 月次の資金予測 毎月15日
09:00 記事を1本書く 毎日
10:00 日報を取り込む 毎日
12:00 記事を公開する(別サイト) 毎日
13:00 今日ぜんぶ動いたか見張る 毎日

いちばん早いのが6時30分、いちばん遅いのが13時です。夜中に動く設定は1つも残していません。

この並びには意味があります。重い処理を朝のうちに終わらせて、全部終わったあとの13時に見張りを置く。こうすると、何かがずれていてもその日の昼のうちに人間が気づけます。夜中に動かして失敗すると、気づくのは翌朝です。半日ぶん遅れます。

「Mac miniは電源を入れっぱなしなんだから夜中でもいいのでは」と思うかもしれません。私も最初はそう考えていました。ただ、電源が入っていることとスリープしていないことは別です。そしてスリープしていなかったかどうかは、あとから確かめるのが面倒です。確かめるのが面倒な条件に自動化を賭けるより、確実に起きている時間帯に寄せるほうが早いという判断です。

実際の開始時刻を、ログから確かめる

ログの時刻は「終わった時刻」かもしれない

ここが落とし穴でした。最初に出した実行ログの [2026-08-25 00:00] という時刻は、スクリプトのどこで作られているかで意味が変わります。今回の処理では、ログを書く行がファイルのいちばん最後にありました。

echo "[$(date '+%Y-%m-%d %H:%M')] 停滞チェックを実行 → $(basename "$OUT")" >> "$AI_LOGS/実行ログ.txt"

つまりこれは終わった時刻です。この処理は数秒で終わるので開始時刻とほぼ同じですが、10分かかる処理なら10分ずれます。ログの時刻を見るときは、まず「それが始まりの時刻なのか終わりの時刻なのか」を確かめてください。

始まりの時刻を残す、いちばん楽な方法

記事を書かせる処理では、実行ごとのログファイル名に開始時刻を入れてあります。スクリプトの頭のほうで一度だけ時刻を取って、それをファイル名に使う形です。

STAMP=$(date '+%Y%m%d-%H%M%S')
LOG="$LOG_DIR/生成_$STAMP.log"

この作りにしておくと、ファイルの一覧を見るだけで開始時刻が分かります。9月10日はこうなっていました。

生成_20260910-090003.log      ← 9時00分03秒に始まった
[2026-09-10 09:06] 記事を作りました  ← 9時06分に終わった

設定は9時00分。実際の開始は9時00分03秒。3秒の誤差で動いています。この日はMacが起きていた、と言い切れます。そして所要時間が約6分だったことも同時に分かります。

いま動かしているスクリプトに開始時刻が残っていないなら、先頭に1行足すだけで済みます。

echo "[$(date '+%Y-%m-%d %H:%M:%S')] 開始" >> ~/scripts/実行の記録.txt

「動かなかった」のか「動いたが失敗した」のかを分ける

時刻が残っていると、まったく別の原因も切り分けられます。うちのログには9月3日と4日にこういう記録があります。

[2026-09-03 07:30] LINEに送れませんでした: URLError <urlopen error [Errno 8] nodename nor servname provided, or not known>
[2026-09-04 07:30] LINEに送れませんでした: URLError <urlopen error [Errno 8] nodename nor servname provided, or not known>

時刻は7時30分ちょうど。設定どおりに動いています。失敗したのは送信先につながらなかったからで、これは回線の問題です。同じ日の7時の処理も、記録上はきちんと7時に動いて同じ理由で失敗していました。

もしこれがスリープによる遅れなら、時刻は7時30分にはなりません。「記録が無い」ならMacが寝ていた疑い、「記録はあるが失敗している」なら中身の問題。この2つは直し方がまったく違うので、時刻を見るだけで探す場所が半分に減ります。

明日、10分で確かめられること

  1. 自分の定時処理が何時に設定されているか、全部書き出す。
    ls ~/Library/LaunchAgents/ で登録されているものの一覧が出ます。中身を見るときは1つずつ、
    plutil -p ~/Library/LaunchAgents/ラベル名.plist
    夜中の時刻が入っているものがあれば、それは遅れる候補です。
  2. ログの時刻が「始まり」か「終わり」かを確かめる。
    スクリプトを開いて date と書いてある行を探し、それがファイルの先頭側か末尾側かを見るだけです。末尾側なら、それは終わった時刻です。
  3. 始まりの時刻を1行足して残す。
    echo "[$(date '+%Y-%m-%d %H:%M:%S')] 開始" >> ~/scripts/実行の記録.txt
    これをスクリプトの先頭に入れておけば、次にずれたときに何時に動いたかが必ず分かります。
  4. 手ではなく、自動実行の仕組みに1回動かしてもらう。
    launchctl kickstart -k gui/$UID/ラベル名
    手で動かして満足しないこと。手で動かしている限り、Macは絶対に起きています。

まとめ

  • 予定時刻にMacが寝ていると、その回は飛ぶのではなく遅れる。起きたあとに実行される
  • うちの実例では、月曜8時の処理が翌日0時に動いた。16時間のずれ
  • 遅れると、実行した日から日付を決めている処理は対象そのものがずれる。売上の集計なら実害になる
  • 「今日の日付で記録があるか」で見張っている仕組みは、遅れた実行を前日は失敗・当日は成功と表示する
  • ログの時刻は、始まりか終わりかを必ず確かめる。末尾で date を呼んでいればそれは終了時刻
  • いちばん確実な対策は、予定時刻をMacが確実に起きている時間帯に寄せること。うちは13個すべてを6時30分〜13時に収めた
  • 全部終わったあとに「今日ぜんぶ動いたか」を見る処理を1つ置く。うちは13時

自動化を「設定した時刻に必ず動くもの」だと思っていると、ずれたときに壊れたと判断してしまいます。実際には壊れていないので、直そうとして触ったほうが事故ります。まずログの時刻を見る。それだけで、直すべきかどうかが分かります。

設定を書き換えたのに動く時刻が変わらない、という別の落とし穴については launchdのplistを直したのに反映されない理由|bootoutとbootstrapの使い方 に書きました。今回の話と合わせて読むと、「いま実際に何時に動いているのか」を自分で確かめられるようになります。

コメント

タイトルとURLをコピーしました