ベンダーアプリケーションで待ち時間の問題が発生しました。strace -Ttttプロセスを実行して、次のようになりました。
[...]
1470166748.946144 open("/opt/app/shdbrth/X ", O_RDONLY) = -1 ENOENT (No such file or directory) <0.000016>
1470166800.850979 open("/opt/app/shdbrth/X38347", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 10 <0.000070>
1470166800.851139 fstat(10, {st_mode=S_IFREG|0660, st_size=0, ...}) = 0 <0.000006>
[...]
~によるとマンページ、-ttt各行のプレフィックスはシステムコール時間です。このオプションは、と括弧-Tの間に通話を処理するのにかかる時間を追加します。しかし、上記の例では、これは本当ではないようです。<>
たとえば、2 番目の行は 1,470,166,800 エポック秒と 850,979 マイクロ秒で始まります。添付のタイマーによると、処理時間は70マイクロ秒です。ただし、次の行は同じエポック秒、851,139マイクロ秒で始まります。これは90マイクロ秒の違いです。
オーバーヘッドで書こうとしましたが、おそらくより正確な説明があるようです。
ベストアンサー1
行の先頭の時間は、カーネルがシステムコール処理を開始した時間です。行末の期間は、カーネルがシステムコール処理を開始した時間と、カーネルがシステムコールに応答する時間との間の間隔です。
次の行が始まる時間は、カーネルが次のシステムコール処理を開始する時間です。 1つのシステムコールに応答し、次のシステムコールを入力する間に2つのことが起こります。プロセスはユーザーコードを実行し、他のプロセスは同じプロセッサで予約できます。
あなたの例では、最初のopen呼び出しは16マイクロ秒かかり、次の呼び出しは約12秒後に発行されました。この12秒間、プロセスはユーザーコードを実行し、他のプロセスを実行するために複数回プリエンプトすることができます。 2回目のopen呼び出しとその後の呼び出しの間に約90μsが経過しましたfstat。この値がどれだけ小さいかを考えると、これはプロセスが少量のユーザーコードのみを実行していてプリエンプトされていないことを意味します。