CentOS7で運用しているサーバで「perf: interrupt took too long (3989 > 3933), lowering kernel.perf_event_max_sample_rate to 50000」というような出力が発生しているのに気がついた。
$ dmesg|grep "kernel.perf_event_max_sample_rate"
[ 1502.981806] perf: interrupt took too long (2512 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
[ 2019.987492] perf: interrupt took too long (3147 > 3140), lowering kernel.perf_event_max_sample_rate to 63000
[ 2910.077414] perf: interrupt took too long (3989 > 3933), lowering kernel.perf_event_max_sample_rate to 50000
$
パフォーマンス情報を取得するために、どれくらいの周期でデータを取得したらいいのかは、サーバのハードウェア構成などによって変化するため、自動調整するようになっているようだ。
まずは、長い間隔で収集（サンプリングレート）し、うまくデータが取れているようだったら、徐々に間隔を短縮していく、ということになっているようだ。
journalctlでログから発生時刻を確認する。
# journalctl |grep "perf_event_max_sample_rate"
2月 27 10:44:11 blog.osakana.net kernel: perf: interrupt took too long (2512 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
2月 27 10:52:48 blog.osakana.net kernel: perf: interrupt took too long (3147 > 3140), lowering kernel.perf_event_max_sample_rate to 63000
2月 27 11:07:38 blog.osakana.net kernel: perf: interrupt took too long (3989 > 3933), lowering kernel.perf_event_max_sample_rate to 50000
#
この日は10:19頃にkernelアップデートのため再起動したことにより、サンプリングレートの値が初期化され、調整が必要になったようだ。
過去のログを遡ってみると「perf: interrupt took too long (5208 > 5190), lowering kernel.perf_event_max_sample_rate to 38000」というのが、一番低い値である模様。
最初の変更後の値が79000ということを考えると、起動時の初期値は80000以上だったと思われるので、周期が半分以下となったということである。
さて、kernel.perf_event_max_sample_rateの現在値は「/proc/sys/kernel/perf_event_max_sample_rate」で確認出来る。
# cat /proc/sys/kernel/perf_event_max_sample_rate
50000
#
値を変更する場合は、上記に値を入れる。
恒久的に変更するには、sysctlの設定ファイルを作成する。
CentOS7の場合、/etc/sysctl.d ディレクトリに設定ファイルを作成する。(/etc/sysctl.confに追加するという手もあるが、今後のパッチでsysctl.confが修正される可能性があるためお薦めしない。)
まず、現在の設定値を確認
# sysctl -a | grep perf_event_max_sample_rate
kernel.perf_event_max_sample_rate = 50000
#
/etc/sysctl.d/90-local.conf として設定値を入れた設定ファイルを作成
# echo "kernel.perf_event_max_sample_rate = 38000" > /etc/sysctl.d/90-local.conf
# cat /etc/sysctl.d/90-local.conf
kernel.perf_event_max_sample_rate = 38000
#
sysctlの設定をシステムに適用します。
# sysctl --system
* Applying /usr/lib/sysctl.d/00-system.conf ...
* Applying /usr/lib/sysctl.d/50-default.conf ...
kernel.sysrq = 16
kernel.core_uses_pid = 1
net.ipv4.conf.default.rp_filter = 1
net.ipv4.conf.all.rp_filter = 1
net.ipv4.conf.default.accept_source_route = 0
net.ipv4.conf.all.accept_source_route = 0
net.ipv4.conf.default.promote_secondaries = 1
net.ipv4.conf.all.promote_secondaries = 1
fs.protected_hardlinks = 1
fs.protected_symlinks = 1
* Applying /etc/sysctl.d/90-local.conf ...
kernel.perf_event_max_sample_rate = 38000
* Applying /etc/sysctl.d/99-sysctl.conf ...
* Applying /etc/sysctl.conf ...
#
値が変更されたことを確認します。
# sysctl -a | grep perf_event_max_sample_rate
kernel.perf_event_max_sample_rate = 38000
#
2017/03/03追記
kernel.perf_event_max_sample_rate の値を調整した後、現在のところは同じメッセージは出力されていません。
2017/03/22追記
約１ヶ月経過しましたが、出力されていないので、うちの環境では38000で問題ないようです。
2018/07/09追記
別環境で作ったサーバでも38000で落ち着きました。