■ 前提
RHEL 9.7 の EC2 インスタンスで検証した結果となる
■ dnf-makecache.timer がトリガーされた時のログを例に見てみる
journalctl コマンドで確認ができる
# journalctl -u dnf-makecache.timer
Apr 29 11:11:35 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: Started dnf makecache --timer.
/var/log/messages でも同様のログが記録されているか確認してみる
記録がある場合
# cat /var/log/messages | grep "dnf makecache"
Apr 29 11:11:35 ip-10-0-28-83 systemd[1]: Started dnf makecache --timer.
記録がない場合
# cat /var/log/messages | grep "dnf makecache"
（出力無し）
/var/log/messages は rsyslog が /dev/log ソケット経由で受け取ったログを書き出すファイルである。
systemd のイベント (unit の Started / Stopped 等) は /dev/log ソケットを経由せず journal に直接書き込まれる動作となる。
imjournal モジュールを用いた rsyslog への転送設定を /etc/rsyslog.conf で行うことにより、journal に記録された systemd のイベントを messages に転送することが可能である。今回検証で使用した EC2 (RHEL 9.7) ではデフォルトで転送設定が入っていた。
以降は、journalctl にオプションを付けて同様のイベントを確認してみる
-o short-precise オプションを付けると、マイクロ秒精度のタイムスタンプで表示
# journalctl -u dnf-makecache.timer -o short-precise
Apr 29 11:11:35.943681 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: Started dnf makecache --timer.
-o cat オプションを付けると、メッセージ (MESSAGE) 部分のみ表示
# journalctl -u dnf-makecache.timer -o cat
Started dnf makecache --timer.
-o verbose オプションを付けると、イベントの詳細情報を表示
# journalctl -u dnf-makecache.timer -o verbose
Wed 2026-04-29 11:11:35.943681 JST [s=47efd485cd674d9eb244e6b541eba355;i=357;b=f07b0d2de8b54fc2beb6e9ec396f64f2;m=4ee9a9;t=6508fde090a0d;x=2f26b05c6fee5e8a]
_BOOT_ID=f07b0d2de8b54fc2beb6e9ec396f64f2
_MACHINE_ID=ec27703ca6990b971b01b4fc80b6d6bb
PRIORITY=6
SYSLOG_FACILITY=3
SYSLOG_IDENTIFIER=systemd
_UID=0
_GID=0
_TRANSPORT=journal
_CAP_EFFECTIVE=1ffffffffff
TID=1
CODE_FILE=src/core/job.c
CODE_LINE=768
CODE_FUNC=job_emit_done_message
JOB_TYPE=start
JOB_RESULT=done
MESSAGE_ID=39f53479d3a045ac8e11786248231fbf
_PID=1
_COMM=systemd
_EXE=/usr/lib/systemd/systemd
_SYSTEMD_CGROUP=/init.scope
_SYSTEMD_UNIT=init.scope
_SYSTEMD_SLICE=-.slice
_HOSTNAME=ip-10-0-28-83.ap-northeast-1.compute.internal
_RUNTIME_SCOPE=system
_CMDLINE=/usr/lib/systemd/systemd --switched-root --system --deserialize 31
_SELINUX_CONTEXT=system_u:system_r:init_t:s0
MESSAGE=Started dnf makecache --timer.
JOB_ID=207
INVOCATION_ID=7045a3f8b3754ace894cf889f6d8aacd
UNIT=dnf-makecache.timer
_SOURCE_REALTIME_TIMESTAMP=1777428695943681
-o json オプションを付けると、イベントの詳細情報を JSON 形式 (1 行) で表示
--no-pager オプションを付けると、less での表示ではなく標準出力に表示できる
# journalctl -u dnf-makecache.timer -o json --no-pager
{"_TRANSPORT":"journal","PRIORITY":"6","CODE_FUNC":"job_emit_done_message","MESSAGE_ID":"39f53479d3a045ac8e11786248231fbf","CODE_FILE":"src/core/job.c","JOB_ID":"207","JOB_RESULT":"done","JOB_TYPE":"start","_SYSTEMD_SLICE":"-.slice","_SYSTEMD_CGROUP":"/init.scope","__REALTIME_TIMESTAMP":"1777428695943693","SYSLOG_IDENTIFIER":"systemd","_HOSTNAME":"ip-10-0-28-83.ap-northeast-1.compute.internal","_CMDLINE":"/usr/lib/systemd/systemd --switched-root --system --deserialize 31","INVOCATION_ID":"7045a3f8b3754ace894cf889f6d8aacd","__MONOTONIC_TIMESTAMP":"5171625","_UID":"0","_EXE":"/usr/lib/systemd/systemd","_RUNTIME_SCOPE":"system","_SELINUX_CONTEXT":"system_u:system_r:init_t:s0","TID":"1","_COMM":"systemd","_SOURCE_REALTIME_TIMESTAMP":"1777428695943681","_SYSTEMD_UNIT":"init.scope","_PID":"1","CODE_LINE":"768","_BOOT_ID":"f07b0d2de8b54fc2beb6e9ec396f64f2","MESSAGE":"Started dnf makecache --timer.","UNIT":"dnf-makecache.timer","_MACHINE_ID":"ec27703ca6990b971b01b4fc80b6d6bb","SYSLOG_FACILITY":"3","_GID":"0","_CAP_EFFECTIVE":"1ffffffffff","__CURSOR":"s=47efd485cd674d9eb244e6b541eba355;i=357;b=f07b0d2de8b54fc2beb6e9ec396f64f2;m=4ee9a9;t=6508fde090a0d;x=2f26b05c6fee5e8a"}
-o json-pretty オプションを付けると、イベントの詳細情報をJSON 形式 (人間が見やすいように整形) で表示
# journalctl -u dnf-makecache.timer -o json-pretty
{
"_SOURCE_REALTIME_TIMESTAMP" : "1777428695943681",
"_SYSTEMD_SLICE" : "-.slice",
"JOB_RESULT" : "done",
"SYSLOG_FACILITY" : "3",
"_BOOT_ID" : "f07b0d2de8b54fc2beb6e9ec396f64f2",
"PRIORITY" : "6",
"__MONOTONIC_TIMESTAMP" : "5171625",
"_PID" : "1",
"CODE_FILE" : "src/core/job.c",
"_SYSTEMD_UNIT" : "init.scope",
"MESSAGE_ID" : "39f53479d3a045ac8e11786248231fbf",
"_MACHINE_ID" : "ec27703ca6990b971b01b4fc80b6d6bb",
"__REALTIME_TIMESTAMP" : "1777428695943693",
"_UID" : "0",
"__CURSOR" : "s=47efd485cd674d9eb244e6b541eba355;i=357;b=f07b0d2de8b54fc2beb6e9ec396f64f2;m=4ee9a9;t=6508fde090a0d;x=2f26b05c6fee5e8a",
"_SYSTEMD_CGROUP" : "/init.scope",
"_RUNTIME_SCOPE" : "system",
"UNIT" : "dnf-makecache.timer",
"_CAP_EFFECTIVE" : "1ffffffffff",
"_TRANSPORT" : "journal",
"JOB_TYPE" : "start",
"_CMDLINE" : "/usr/lib/systemd/systemd --switched-root --system --deserialize 31",
"_COMM" : "systemd",
"CODE_FUNC" : "job_emit_done_message",
"TID" : "1",
"INVOCATION_ID" : "7045a3f8b3754ace894cf889f6d8aacd",
"_GID" : "0",
"_SELINUX_CONTEXT" : "system_u:system_r:init_t:s0",
"SYSLOG_IDENTIFIER" : "systemd",
"CODE_LINE" : "768",
"MESSAGE" : "Started dnf makecache --timer.",
"JOB_ID" : "207",
"_EXE" : "/usr/lib/systemd/systemd",
"_HOSTNAME" : "ip-10-0-28-83.ap-northeast-1.compute.internal"
}
■ dnf-makecache.timer によって起動された dnf-makecache.service のログも見てみる
journalctl コマンドで確認ができる
# journalctl -u dnf-makecache.service
Apr 29 11:52:25 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: Starting dnf makecache...
Apr 29 11:52:26 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Updating Subscription Management repositories.
Apr 29 11:52:26 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Unable to read consumer identity
Apr 29 11:52:26 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: This system is not registered with an entitlement server. You can use "rhc" or "subscription-manager" to register.
Apr 29 11:52:26 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Red Hat Enterprise Linux 9 for x86_64 - AppStre 47 kB/s | 4.5 kB 00:00
Apr 29 11:52:27 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Red Hat Enterprise Linux 9 for x86_64 - AppStre 130 MB/s | 88 MB 00:00
Apr 29 11:52:45 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Red Hat Enterprise Linux 9 for x86_64 - BaseOS 61 kB/s | 4.1 kB 00:00
Apr 29 11:52:45 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Red Hat Enterprise Linux 9 Client Configuration 30 kB/s | 1.5 kB 00:00
Apr 29 11:52:47 ip-10-0-28-83.ap-northeast-1.compute.internal dnf[1731]: Metadata cache created.
Apr 29 11:52:47 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: dnf-makecache.service: Deactivated successfully.
Apr 29 11:52:47 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: Finished dnf makecache.
Apr 29 11:52:47 ip-10-0-28-83.ap-northeast-1.compute.internal systemd[1]: dnf-makecache.service: Consumed 21.206s CPU time.
上述した dnf-makecache.timer がトリガーされた日時は Apr 29 11:11:35 だった。
一方で、dnf-makecache.timer によって dnf-makecache.service が起動されたのは Apr 29 11:52:25となり、timer のトリガーから 約 41 分後であることが分かる。これはなぜだろうか？
→ 答えは dnf-makecache.timer の RandomizedDelaySec=60m の設定にある。
dnf-makecache.timer の unit file を見てみると、RandomizedDelaySec=60m という設定 (ディレクティブ) があることが分かる。これは「タイマーがトリガーされた後、0～60 分までの範囲のランダムな時間遅延した上で、Unit=dnf-makecache.service を起動する」という設定となる。
# cat /usr/lib/systemd/system/dnf-makecache.timer
[Unit]
Description=dnf makecache --timer
ConditionKernelCommandLine=!rd.live.image
# See comment in dnf-makecache.service
ConditionPathExists=!/run/ostree-booted
Wants=network-online.target
[Timer]
OnBootSec=10min
OnUnitInactiveSec=1h
RandomizedDelaySec=60m
Unit=dnf-makecache.service
[Install]
WantedBy=timers.target
■ (参考) 「RandomizedDelaySec=」ディレクティブについて
RandomizedDelaySec= の目的は、timer ユニットによって起動されるタイミングにランダムな遅延時間を加えることで、同じタイミングに処理 (負荷) が集中することを避けることである
以下、man systemd.timer より RandomizedDelaySec= 部分の説明
(日本語 機械翻訳)
RandomizedDelaySec=
タイマーの遅延時間を、0 から指定された時間値までの範囲で、均等に分布したランダムな値に設定します。
デフォルトは 0 で、ランダムな遅延は適用されません。
各タイマーユニットは、各反復の前にこの遅延時間をランダムに決定します。この遅延時間は、FixedRandomDelay= で変更されていない限り、次に決定される経過時間に単純に加算されます（詳細は後述）。
この設定は、同様の構成を持つタイマーイベントの発火を特定の時間間隔に分散させ、それらがすべて同時に発火してリソースの混雑を引き起こすのを防ぐのに役立ちます。
上記の AccuracySec= との関連性に注意してください。後者は、ウェイクアップを最小限に抑えるために、サービスマネージャーが指定された時間範囲内のタイマーイベントを結合することを可能にするのに対し、この設定は逆の動作を行います。つまり、タイマーイベントを時間間隔に分散させ、それらが同時に発火する可能性を低くします。
RandomizedDelaySec= と AccuracySec= を併用する場合、まずランダムな遅延が追加され、その結果がシステム上で発生している他のタイマーイベントと結合されるよう、さらにシフトされる可能性があります。
前述の通り、AccuracySec=のデフォルト値は1分、RandomizedDelaySec=は0であるため、タイマーイベントの結合が促進されます。
タイマーイベントを特定の時間範囲に最適に分散させるには、AccuracySec=を1usに設定し、RandomizedDelaySec=をそれより大きい値に設定してください。
(英語 原文)
RandomizedDelaySec=
Delay the timer by a randomly selected, evenly distributed amount of time between 0 and the specified time value.
Defaults to 0, indicating that no randomized delay shall be applied.
Each timer unit will determine this delay randomly before each iteration, and the delay will simply be added on top of the next determined elapsing time, unless modified with FixedRandomDelay=, see below.
This setting is useful to stretch dispatching of similarly configured timer events over a certain time interval, to prevent them from firing all at the same time, possibly resulting in resource congestion.
Note the relation to AccuracySec= above: the latter allows the service manager to coalesce timer events within a specified time range in order to minimize wakeups, while this setting does the opposite: it stretches timer events over an interval, to make it unlikely that they fire simultaneously.
If RandomizedDelaySec= and AccuracySec= are used in conjunction, first the randomized delay is added, and then the result is possibly further shifted to coalesce it with other timer events happening on the system.
As mentioned above AccuracySec= defaults to 1 minute and RandomizedDelaySec= to 0, thus encouraging coalescing of timer events.
In order to optimally stretch timer events over a certain range of time, set AccuracySec=1us and RandomizedDelaySec= to some higher value.