
MacOS Yosemite (10.10.5)。これは Unix/Linux セクションであることは承知していますが、この質問は MacOS よりもこちらの方が適していると思われます。
ターミナルは起動時にプロンプトが表示される前にハングし始めました...そして同時に CPU 使用率が急上昇しました。CTRL-C を押すとプロンプトが表示されます (おそらくハングまたは実行中の .bashrc/.profile などを終了していると思われます)。
すぐに、.bashrc 内の特定の行がハングの原因になっていることが分かりました。これは新しい現象です (つまり、.bashrc では何も変更しておらず、すべて正常に動作していました)。そのため、システムで何かが変更されました。
特定の長い文字列をパイプすると、ハングや CPU スパイクが発生するようです。
文字列をパイプしてハングするかどうかを確認することで、これを再現できますtr -d '\n'
。
macattack:~ $ openssl rand -base64 93 | tr -d '\n'
eDsz4JqFX/HAVjplNI6WDWwPRp9l9snp6UKp/pLn+GbBvJx0+ZMvSJFS/SuCwjMRRXVXfUvBdkaH1R0UgCr2UOf283MvHVTRusLFEVPcGCIz1t3sFMU/3foRzNWVmattp@macattack:~ $ openssl rand -base64 94 | tr -d '\n'
^C
mattp@macattack:~ $ openssl rand -base64 94 | tr -du '\n'
^C
93 文字は、tr がハングし始める魔法の数字のようです。openssl はハングしません (つまり、パイプを削除すればtr
すべてが終了します)。ただし、元の問題行の長さが異なっていました。
mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log;' | tr -d '\n'
^C-bash: echo: write error: Interrupted system call
mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log' | tr -d '\n'
mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log' | wc -c
128
mattp@macattack:~ $
これはおそらく問題ではなくパイプの問題です。 (コマンドは意味をなさない...ハングを示すだけです)tr
で同じ問題を再現できます。sed
mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log;' | sed 's/\n/ /g'
^C-bash: echo: write error: Interrupted system call
mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log' | sed 's/\n/ /g'
echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log
mattp@macattack:~
これをトラブルシューティングするアイデアが尽きました。
ハングしているコマンドは、ランダムな Centos Linux サーバーでは正常に実行されます。コマンドは最近まで Macos で正常に実行されていました。パイプのハングに遭遇したことは一度もありません。入力内の奇妙な文字が問題の原因かもしれないと思いましたが、openssl のランダム文字列はそうではないことを示しています。ulimits は、同じ問題が発生していない別の Mac と同じです。
mattp@macattack:~ $ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) unlimited
max memory size (kbytes, -m) unlimited
open files (-n) 7168
pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 709
virtual memory (kbytes, -v) unlimited
dtruss
これを使用するとtr
、read_nocancel 呼び出しでハングするようです。
アップデート
進展しています。ハングとパイプ バッファ サイズに関するコメントを見つけました。ここからテスト スクリプトを盗みました: パイプバッファの大きさはどれくらいですか?
問題が発生している間に実行すると、パイプ バッファが 128 バイトと表示されます。再起動すると (問題は一時的に解消されます)、パイプ バッファは 65536 バイトになります。以下のテスト出力を参照してください。
そこで疑問になるのは、「何か」がなぜ/どのようにしてシステム上のパイプ バッファー サイズを削減するのかということです。
問題あり
$ /bin/bash -c 'for p in {0..18}; do pipe-buffer-test.sh $((2 ** $p)) 0.5; done'
write size: 1; bytes successfully before error: 128
write size: 2; bytes successfully before error: 128
write size: 4; bytes successfully before error: 128
write size: 8; bytes successfully before error: 128
write size: 16; bytes successfully before error: 128
write size: 32; bytes successfully before error: 128
write size: 64; bytes successfully before error: 128
write size: 128; bytes successfully before error: 128
write size: 256; bytes successfully before error: 0
write size: 512; bytes successfully before error: 0
write size: 1024; bytes successfully before error: 0
write size: 2048; bytes successfully before error: 0
write size: 4096; bytes successfully before error: 0
write size: 8192; bytes successfully before error: 0
write size: 16384; bytes successfully before error: 0
write size: 32768; bytes successfully before error: 0
write size: 65536; bytes successfully before error: 0
write size: 131072; bytes successfully before error: 0
write size: 262144; bytes successfully before error: 0
再起動後(問題は一時的に解消)
$ /bin/bash -c 'for p in {0..18}; do pipe-buffer-test.sh $((2 ** $p)) 0.5; done'
write size: 1; bytes successfully before error: 65536
write size: 2; bytes successfully before error: 65536
write size: 4; bytes successfully before error: 65536
write size: 8; bytes successfully before error: 65536
write size: 16; bytes successfully before error: 65536
write size: 32; bytes successfully before error: 65536
write size: 64; bytes successfully before error: 65536
write size: 128; bytes successfully before error: 65536
write size: 256; bytes successfully before error: 65536
write size: 512; bytes successfully before error: 65536
write size: 1024; bytes successfully before error: 65536
write size: 2048; bytes successfully before error: 65536
write size: 4096; bytes successfully before error: 65536
write size: 8192; bytes successfully before error: 65536
write size: 16384; bytes successfully before error: 65536
write size: 32768; bytes successfully before error: 65536
write size: 65536; bytes successfully before error: 65536
write size: 131072; bytes successfully before error: 0
write size: 262144; bytes successfully before error: 0
答え1
@Barmar のカーネルバッファのリークに関するコメントに基づいて、現在の非 OS kext を調べてみました。最近インストールした BlockBlock から比較的新しいものがあることに気付きました (https://objective-see.com/products/blockblock.html)。
BlockBlock をアンインストールして再起動しましたが、問題は再発しませんでした。したがって、このケースでは BlockBlock が犯人であり、この問題を作者に報告しました。
しかし、原因を突き止めるために推測と確認のアプローチを主に採用したため、これは特に満足のいくものではありません。正直なところ、根本的な原因(OS の観点から)を本当に理解していないため、将来この種の問題をトラブルシューティングする際に何の助けにもなりません。
誰かがこれに遭遇し、何が起こっていたのかをより詳しく説明し、トラブルシューティングのアプローチを提供できる場合、それは「BlockBlock をアンインストールする」よりもはるかに良い答えになります。