Linux,システムコールの処理時間や発行された時刻を確認する

スポンサーリンク

鍛錬 787

Linux,システムコールの処理時間や発行された時刻を確認する

プログラム(プロセス)実行時に発行されたシステムコールについて、処理にかかった時間や発行された時刻を確認するには、strace を使用します。

関連記事:Linux,プログラムが発行したシステムコールを確認する
 
使用方法は、以下に示す通りです。

システムコールの処理にかかった時間を確認する

strace -T 実行するプログラムのパス

 
システムコールが発行された時刻を確認する

strace -t 実行するプログラムのパス

 
システムコールが発行された時刻(マイクロ秒単位)を確認する

strace -tt 実行するプログラムのパス

 
システムコールが発行された時刻(UNIX時間でのマイクロ秒単位)を確認する

strace -ttt 実行するプログラムのパス

オプション

以下は、上記のオプションについてです。

オプション 機能
-T 処理にかかった時間を確認する
-t 発行された時刻を確認する
-tt 発行された時刻をマイクロ秒単位で確認する
-ttt 発行された時刻をマイクロ秒単位のUNIX時間で確認する
スポンサーリンク

プログラム

以下は、システムコールの時刻情報を確認する際に実行するプログラム、test_strace.c です。

今回はC言語で作成しています。

// include
#include <stdio.h>

// main
int main(void)
{
	printf("Hello\n");
	
	return 0;
}
スポンサーリンク

実行結果

以下は、プロセスが発行したシステムコールの時刻情報について確認しています。

処理にかかった時間を確認

以下は、プログラム test_strace.c を実行して、発行されたシステムコールの処理にかかった時間を確認しています。

処理にかかった時間は、各行末に表示されます。

例:17マイクロ秒かかった場合
  ・・・・・ <0.000017>

***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ strace -T -o test_strace.txt ./test_strace
Hello
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ cat test_strace.txt
execve("./test_strace", ["./test_strace"], 0x7ffc236b4f48 /* 67 vars */) = 0 <0.000104>
brk(NULL)                               = 0x5610bebaf000 <0.000003>
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory) <0.000006>
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory) <0.000004>
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000006>


   (中略)


brk(NULL)                               = 0x5610bebaf000 <0.000006>
brk(0x5610bebd0000)                     = 0x5610bebd0000 <0.000004>
write(1, "Hello\n", 6)                  = 6 <0.000067>
exit_group(0)                           = ?
+++ exited with 0 +++

 
上記に示した通り、システムコールの処理にかかった時間を確認することができました。

システムコール「write」が発行された際、処理に67マイクロ秒かかったことが分かります。

発行された時刻(マイクロ秒単位)を確認

以下は、システムコールが発行された時刻をマイクロ秒単位で確認しています。

各項目の先頭に時刻が表示されます。

***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ date
Sun Mar 15 02:04:45 JST 2020
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ strace -tt -o test_strace.txt ./test_strace
Hello
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ cat test_strace.txt
02:04:46.686261 execve("./test_strace", ["./test_strace"], 0x7fffa37960b8 /* 67 vars */) = 0
02:04:46.686495 brk(NULL)               = 0x55fcef56c000
02:04:46.686530 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
02:04:46.686558 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
02:04:46.686579 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3


   (中略)


02:04:46.687313 brk(NULL)               = 0x55fcef56c000
02:04:46.687327 brk(0x55fcef58d000)     = 0x55fcef58d000
02:04:46.687345 write(1, "Hello\n", 6)  = 6
02:04:46.687436 exit_group(0)           = ?
02:04:46.687497 +++ exited with 0 +++

 
上記に示した通り、システムコールが発行された時刻を確認することができました。

システムコール「write」が発行された時刻は 2時4分46.687345秒 であることが分かります。

発行された時刻を確認(UNIX時間)

以下は、システムコールが発行された時刻をマイクロ秒単位のUNIX時間で確認しています。

各項目の先頭に時刻が表示されます。

***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ date
Sun Mar 15 02:07:39 JST 2020
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ strace -ttt -o test_strace.txt ./test_strace
Hello
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ 
***@ubuntu:~/***/test/c$ cat test_strace.txt
1584205660.722427 execve("./test_strace", ["./test_strace"], 0x7fff043c2488 /* 67 vars */) = 0
1584205660.722623 brk(NULL)             = 0x560578959000
1584205660.722653 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
1584205660.722679 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
1584205660.722695 openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3


   (中略)


1584205660.723300 brk(NULL)             = 0x560578959000
1584205660.723316 brk(0x56057897a000)   = 0x56057897a000
1584205660.723338 write(1, "Hello\n", 6) = 6
1584205660.723378 exit_group(0)         = ?
1584205660.723542 +++ exited with 0 +++

 
上記に示した通り、システムコールが発行された時刻をUNIX時間で確認することができました。

システムコール「write」が発行された時刻は 1584205660.723338 (UNIX時間)であることが分かります。

タイトルとURLをコピーしました