perf: interrupt took too longというメッセージがmessagesに記録される





 参考URL:CentOS7のdmesgにperf: interrupt took too longに関するメッセージが出力される

 /var/log/messagesを眺めていたところ下記のようなログが記録されていることに気がつきました。

Oct 26 08:44:38 serverA kernel: perf: interrupt took too long (2504 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
Oct 26 08:58:51 serverA kernel: perf: interrupt took too long (2504 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
Oct 26 09:08:58 serverA kernel: perf: interrupt took too long (3137 > 3130), lowering kernel.perf_event_max_sample_rate to 63000


 Kernelをアップデートし、再起動後に表示されました。
 パフォーマンス情報を取得するためにどれくらいの周期でデータを取得したら良いかを自動調整しているらしい。
 パフォーマンス情報の取得は、ハードウェア構成等により変化し、ある長い周期(サンプリングレート)で問題なく取得できているようであればだんだん周期を短くしていくという動作らしい。

 journalctlのログからでも確認できます。

10月 26 08:58:51 serverA.bigbang.mydns.jp kernel: perf: interrupt took too long (2504 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
10月 26 09:08:58 serverA.bigbang.mydns.jp kernel: perf: interrupt took too long (3137 > 3130), lowering kernel.perf_event_max_sample_rate to 63000
10月 26 09:28:03 serverA.bigbang.mydns.jp kernel: perf: interrupt took too long (3923 > 3921), lowering kernel.perf_event_max_sample_rate to 50000


 Kernelをアップデート後の再起動により、サンプリングレートの値が初期化され調整が必要になったようです。

 kernel.perf_event_max_sample_rateの現在設定されている値は「/proc/sys/kernel/perf_event_max_sample_rate」で確認できます。
# cat /proc/sys/kernel/perf_event_max_sample_rate
63000
 設定値を変更したい場合は、上記に反映させてください。

 恒久的に変更する場合は、sysctlの設定ファイルを作成します。
 CentOS7の場合、/etc/sysctl.d ディレクトリに設定ファイルを作成します。
 (/etc/sysctl.confに追加するという手もありますが、今後のパッチで変更される可能性があるらしい、ということです。)
 こちらの作業は、上記、参考URLを確認してください。