shinichi_gotoh
2023年1月20日 12時36分
お世話になります。後藤と申します。
普段、何種類かの Armadillo 上で動作するシステムの開発を行っております。
今回の質問は、Armadillo-420 でのカーネル？のメモリーリーク？についてです。
もう5年以上動作させているシステムで（１年に１度はメンテナンスで電源断をしています）、
軽微な改造があってソフトウェアをバージョンアップしたところ、10台以上のシステムが約５ヶ月程度経過しところで、パラパラと停止し始めてしまいました。
改造箇所にメモリリークが潜んでいるものだろうと調査を行ったのですが、プロセス毎のメモリ使用状況（/proc/*/status）も含め、問題がありそうな箇所はありませんでした。
その調査中に、meminfo の値で普段みなれない数値の項目がありました。
MemTotal: 61416 kB
・
Slab: 31316 kB
SReclaimable: 1168 kB
SUnreclaim: 30148 kB
Slabの解放できないものが31MB程度になっているではありませんか。
しかし、停止した装置は即刻復旧する必要があったため、思いつくログを一気に取得し再起動を行ったのですが、残念ながら slabinfo は取得していませんでした。
（実機は遠隔地で頻繁には出入りできません）
現在はダミー環境を社内で作って調査を行っているのですが、確かに1時間あたり6.5kB程度ずつ SUnreclaim が増加しており現場と一致します。
カーネルのキャッシュ解放をしても、この SUnreclaim の値にはほぼ影響せず減ることはありません。
そこで slabinfo を確認したところ、pid という項目が増大し続けていることを見つけました。
このpid の増加に合わせて SUnreclaim も増えている事を突き止めましたが、私はこの pid の意味を説明できる知識を持ち合わせておりません。
この pid の明確な意味をご存じの方はいらっしゃいますでしょうか。
また、この値は何をすれば増えるのか、解放する手立てはあるのか、ご教示頂ければと思います。
※ちなみに、軽微な改造を入れる前のシステムで元々発生していたのか、今回の改造後からなのかは、リソースが足らず調査しておりません。
もしかしたら以前から発生していたのがギリギリ１年耐えられるものが、今回の軽微な改造で露見しただけかもしれませんので、そこの確認もしたいところなのですが。。。
コメント
shinichi_gotoh
2023年1月20日 18時24分
自己レスです。
このフォーラムに質問を書かせて頂いた直後、嘘のような偶然で現場で事象が発生し、ログを取る事ができました。
現場のslabinfo のpid値が以下のようになっていました。
pid 403029 403029 64 59 1 : tunables 120 60 0 : slabdata 6831 6831 0
やはりこれが要因のようでした。
さらに、動作しているモジュールを１つ１つkillしていったところ、pppd コマンドに行き着きました（100%間違いない、とは言い切れていませんが）。
本システムは値を計測してため込むロガーのような装置です。
装置にはLTEモデムが付いており、外部からいつでもデータが取得できるように、RING待ちをしています。
ただしアンテナレベルの最新値も常に保存しておくため、RINGが無い場合、
pppdは10秒でタイムアウトし、自作プログラムでATコマンドでアンテナレベルを取得し、またpppdでRING待ちをしています。
最初の質問に書いた軽微な改造というのは、このアンテナレベル取得周期を60秒から10秒に変更したものです。
コマンドの呼び出し頻度が上がったことで、1年では出なかった事象が露呈したものと思います。
ちなみに、pppd を使ったRING待ちは、ppp接続をやっておられる方はたぶん見たことがあるであろう、ppp-on-dialer がベースです。
#!/bin/sh
exec chat -v \
TIMEOUT 10 \
ABORT '\nBUSY\r' \
ABORT '\nNO ANSWER\r' \
ABORT '\nRINGING\r\n\r\nRINGING\r' \
'' \rAT \
'OK-+++\c-OK' ATH0 \
TIMEOUT 20 \
RING ATA \
CONNECT '\d\c' \
改めて質問です。pppdコマンドでは、このような問題報告はございませんでしょうか。
at_mizo
2023年1月23日 9時34分
溝渕です。
> pppdコマンドでは、このような問題報告はございませんでしょうか。
pppdの問題であれば、プロセスが大量に生成される等しているように思います。問題が発生している状況で、以下のコマンドを事項してみていただけますか?
[armadillo]# ps axu
Linux kernel側からだと、以下のパッチが気になりました。
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/comm…
commit messageを見るとen-bugの修正っぽいのですが、コードパスを見るとlinux-3.14-atにも該当するように思います。
linux-3.14-at用に作り直したパッチを添付します。
| ファイル | ファイルの説明 |
|---|---|
| linux-3.14-at.patch |
shinichi_gotoh
2023年1月24日 1時36分
溝渕さん
後藤です、ご回答ありがとうございます。
また、パッチありがとうございました。
> pppdの問題であれば、プロセスが大量に生成される等しているように思います。問題が発生している状況で、以下のコマンドを事項してみていただけますか?
pppdが直接悪さをしているとは思ってはいないのですが、pppdの使い方が正しくないが故に、誤動作を引き起こすような事案のご報告がもしあったりすればと思いました。
もちろん、プロセスが大量に残っていれば悩む事はないのですが、プロセスは跡形もありません。
ではなぜpppdが関連したと思っているかと申しますと、pppd を呼び出すだけの小さなプログラムを作って試したところ、メモリリークサイズがpppdの呼び出し頻度に連動している事に気が付いたからです。
main()
{
for (;;) {
system("pppd /dev/ttymxc1 19200 connect /etc/ppp/ppp-on-dialer-ring");
for (;;) {
FILE *fp = popen("ps | grep pppd | grep -cv grep", "r");
if (fp) {
char buf[10];
buf[0] = '\0';
fgets(buf, sizeof buf, fp);
fclose(fp);
if (buf[0] == '0') break;
sleep(1);
}
}
}
}※Cの記述についての突っ込みは無しということで(^_^;
ppp-on-dialer-ring
#!/bin/sh exec chat -v \ TIMEOUT 10 \ ABORT '\nBUSY\r' \ ABORT '\nNO ANSWER\r' \ ABORT '\nRINGING\r\n\r\nRINGING\r' \ '' \rAT \ 'OK-+++\c-OK' ATH0 \ TIMEOUT 20 \ RING ATA \ CONNECT '\d\c' \
ppp-on-dialer-ring の TIMEOUT 10 を長くしたり短くしたりで、slabinfo の pid が溜まっていく速度が異なります。
また、これは別問題ですが、以前から pppd による接続をkillコマンドで停止させると、タイミングによって chat コマンドのゾンビが残るという問題があります。
実はこの問題も解決できておらず、chat プロセスが消えるまでchatプロセスをkillする処理で現在対処しています（1度のkillでは消えない事も多いので）。
ですので、chat問題も含めて、pppd の使い方自体が間違っているのではないか？という疑念から、ご質問に至ったという経緯です。
> Linux kernel側からだと、以下のパッチが気になりました。
>
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/comm…
>
> commit messageを見るとen-bugの修正っぽいのですが、コードパスを見るとlinux-3.14-atにも該当するように思います。
>
> linux-3.14-at用に作り直したパッチを添付します。
ご返信頂き、環境を書いていない事に気がつきました。
現在のkernelは 2.6.26-at28 でした、申し訳ございません。
en-bugのようでしたが、2.6.26-at28 の af_unix.c もロジックはほぼ同一でしたので、ダメ元で 2.6.26-at28 の af_unix.c に手動でパッチをあててみましたが状態の改善には至りませんでした。
引き続き、何か思い当たるものがございましたら、宜しくお願い致します。
at_mizo
2023年1月24日 11時28分
溝渕です。
ご確認ありがとうございます。
> また、これは別問題ですが、以前から pppd による接続をkillコマンドで停止させると、タイミングによって chat コマンドのゾンビが残るという問題があります。
> 実はこの問題も解決できておらず、chat プロセスが消えるまでchatプロセスをkillする処理で現在対処しています（1度のkillでは消えない事も多いので）。
>
> ですので、chat問題も含めて、pppd の使い方自体が間違っているのではないか？という疑念から、ご質問に至ったという経緯です。
pppdのシグナルのハンドリングが良くなさそうですね。
現在の問題の本質は、slabのメモリリークと認識しています。この問題の発生のきっかけがuserlandであったとしても、メモリリークが発生する以上、kernelには問題があると思います。
> ご返信頂き、環境を書いていない事に気がつきました。
> 現在のkernelは 2.6.26-at28 でした、申し訳ございません。
こちらこそすみません。事前に確認すべきでした。
ちなみにですが、linux-3.14-atで動作させる事は可能ですか? もし改善した場合、問題がuserland/kernelのどちらであるかの切り分けになると思います。
shinichi_gotoh
2023年1月24日 15時35分
溝渕さん
早速のご返信、ありがとうございます。
> 現在の問題の本質は、slabのメモリリークと認識しています。この問題の発生のきっかけがuserlandであったとしても、メモリリークが発生する以上、kernelには問題があると思います。
そうですね、話がそれすぎてしまいましたが、最初のタイトルの通り、本質はSlabのメモリリークの改善でした。
> ちなみにですが、linux-3.14-atで動作させる事は可能ですか? もし改善した場合、問題がuserland/kernelのどちらであるかの切り分けになると思います。
おっしゃる通り、それが切り分けできる最良の方法ですね。切り分けのために動作させる事は可能ではあります。
なのですが、万が一カーネルバージョンアップで改善した場合でも、実際の現場にそれを反映させることは費用と時間から現在のところ不可能なので後回しにしてしまっていました。
しかし、やはり3.14で動作させて、切り分け作業はやらざるを得ない状況ですね。
現場はタイムアウト時間を長くして、延命をはかろうと思います。
カーネルのバージョンを上げて試して、結果が出ましたら、またご報告いたします。
shinichi_gotoh
2023年3月7日 18時56分
遅くなりましたが、自己レス、結果報告です。
自身のプログラムが問題を起こしている可能性を排除するため、アットマークテクノ殿が公開している、素の状態のカーネルとユーザーランドで処理を実行したところ、以下のような結果となりました。
メモリリークが発生する→×
メモリリークは発生しない→○
armadillo-420：kernel version 2.6.26：×
armadillo-420：kernel version 3.14：○
armadillo-440：kernel version 2.6.26：×
armadillo-440：kernel version 3.14：○
※armadillo-440はメモリが倍あるため、事象は発生しにくい状態ですが着実に増加していきます。
ということで、kernel version 2.6.26 において、pppd または chat コマンドに内在しているなんらかの不具合により、カーネルの解放出来ないメモリが増大していく事は間違いありませんでした。
また、kernel version 3.14 では、同様の不具合は解消されていることも判りました。
カーネルのバージョンアップを行う予算も時間も無いため、今回は pppd コマンドのタイムアウトを長くして延命することとします。
ご回答頂いた皆様、ありがとうございました。
at_shinya.koga
2023年1月20日 15時05分
アットマークテクノの古賀です。
後藤さん：
>現在はダミー環境を社内で作って調査を行っているのですが、確かに1時間あたり6.5kB程度ずつ SUnreclaim が増加しており現場と一致します。
>カーネルのキャッシュ解放をしても、この SUnreclaim の値にはほぼ影響せず減ることはありません。
>そこで slabinfo を確認したところ、pid という項目が増大し続けていることを見つけました。
>このpid の増加に合わせて SUnreclaim も増えている事を突き止めましたが、私はこの pid の意味を説明できる知識を持ち合わせておりません。
>
>この pid の明確な意味をご存じの方はいらっしゃいますでしょうか。
struct pid の slab キャッシュのようですね：
https://elixir.bootlin.com/linux/v3.14/source/kernel/pid_namespace.c#L53
https://elixir.bootlin.com/linux/v3.14/source/include/linux/pid.h#L57
https://elixir.bootlin.com/linux/v3.14/source/kernel/pid.c#L294
>その調査中に、meminfo の値で普段みなれない数値の項目がありました。
>MemTotal: 61416 kB
>・
>Slab: 31316 kB
>SReclaimable: 1168 kB
>SUnreclaim: 30148 kB
>
>Slabの解放できないものが31MB程度になっているではありませんか。
>しかし、停止した装置は即刻復旧する必要があったため、思いつくログを一気に取得し再起動を行ったのですが、残念ながら slabinfo は取得していませんでした。
>（実機は遠隔地で頻繁には出入りできません）
…
>また、この値は何をすれば増えるのか、解放する手立てはあるのか、ご教示頂ければと思います。
回答ではなく恐縮ですが、検索してみたところ、RedHat の登録ユーザー向け Knowledgebase に、以下の記事がありました：
Constant memory usage increase in pid slab
https://access.redhat.com/solutions/5504901
が、この記事の本文を見るには、RedHat のカスタマーアカウントが必要なようです。
ちなみに、/proc/slabinfo の pid の行で、tunables 欄は、どのようになっているでしょうか？