From 0d9c1df75a17457366a64228682ebc3cf48ec50c Mon Sep 17 00:00:00 2001 From: Ken Sato Date: Fri, 16 Mar 2018 11:14:29 +0900 Subject: [PATCH] update: testcases and result for #1032, #1033, #1034 --- test/mng_mod/issues/1032-34/CT_003.c | 4 +- test/mng_mod/issues/1032-34/CT_006.c | 4 +- test/mng_mod/issues/1032-34/CT_007.c | 3 +- test/mng_mod/issues/1032-34/CT_008.c | 7 +- test/mng_mod/issues/1032-34/CT_009.c | 2 +- test/mng_mod/issues/1032-34/README | 17 ++-- test/mng_mod/issues/1032-34/result.log | 107 +++++++++++++++---------- 7 files changed, 87 insertions(+), 57 deletions(-) diff --git a/test/mng_mod/issues/1032-34/CT_003.c b/test/mng_mod/issues/1032-34/CT_003.c index c5affca3..ad4928fe 100644 --- a/test/mng_mod/issues/1032-34/CT_003.c +++ b/test/mng_mod/issues/1032-34/CT_003.c @@ -72,11 +72,11 @@ int main(int argc, char* argv[]) printf("[ RUSAGE_SELF ]\n"); OKNG(delta_utime < (1.9 * ONE_SEC) || delta_utime > (2.1 * ONE_SEC), - " utime: %d.%06d s (+ %d.%06d s)", + " utime: %d.%06d s (+ %d.%06d s) <- サブスレッド増分2秒", (cur_utime / ONE_SEC), (cur_utime % ONE_SEC), (delta_utime / ONE_SEC), (delta_utime % ONE_SEC)); OKNG(delta_stime < (3.9 * ONE_SEC) || delta_stime > (4.1 * ONE_SEC), - " stime: %d.%06d s (+ %d.%06d s)", + " stime: %d.%06d s (+ %d.%06d s) <- サブスレッド増分1秒 + メインスレッドjoin待ち3秒", (cur_stime / ONE_SEC), (cur_stime % ONE_SEC), (delta_stime / ONE_SEC), (delta_stime % ONE_SEC)); diff --git a/test/mng_mod/issues/1032-34/CT_006.c b/test/mng_mod/issues/1032-34/CT_006.c index f97f3aef..3b27994f 100644 --- a/test/mng_mod/issues/1032-34/CT_006.c +++ b/test/mng_mod/issues/1032-34/CT_006.c @@ -73,11 +73,11 @@ int main(int argc, char* argv[]) printf("[ RUSAGE_CHILDREN ]\n"); OKNG(cur_utime != 0, - " utime: %d.%06d s (+ %d.%06d s)", + " utime: %d.%06d s (+ %d.%06d s) <- 子プロセスが未終了のため、0", (cur_utime / ONE_SEC), (cur_utime % ONE_SEC), (delta_utime / ONE_SEC), (delta_utime % ONE_SEC)); OKNG(cur_stime != 0, - " stime: %d.%06d s (+ %d.%06d s)", + " stime: %d.%06d s (+ %d.%06d s) <- 子プロセスが未終了のため、0", (cur_stime / ONE_SEC), (cur_stime % ONE_SEC), (delta_stime / ONE_SEC), (delta_stime % ONE_SEC)); diff --git a/test/mng_mod/issues/1032-34/CT_007.c b/test/mng_mod/issues/1032-34/CT_007.c index 191fc0d9..da13f44f 100644 --- a/test/mng_mod/issues/1032-34/CT_007.c +++ b/test/mng_mod/issues/1032-34/CT_007.c @@ -80,7 +80,8 @@ int main(int argc, char* argv[]) printf("[ RUSAGE_CHILDREN ]\n"); OKNG(cur_maxrss < 16 * 1024 || cur_maxrss > 32 * 1024, - " maxrss: %d KB (+ %d KB)", cur_maxrss, delta_maxrss); + " maxrss: %d KB (+ %d KB) <- 子プロセス終了後に更新される", + cur_maxrss, delta_maxrss); prev_maxrss = cur_maxrss; diff --git a/test/mng_mod/issues/1032-34/CT_008.c b/test/mng_mod/issues/1032-34/CT_008.c index 19462d22..5a03c8ba 100644 --- a/test/mng_mod/issues/1032-34/CT_008.c +++ b/test/mng_mod/issues/1032-34/CT_008.c @@ -123,15 +123,16 @@ int main(int argc, char* argv[]) printf("[ RUSAGE_CHILDREN ]\n"); OKNG(cur_utime < (2.9 * ONE_SEC) || delta_utime > (3.1 * ONE_SEC), - " utime: %d.%06d s (+ %d.%06d s)", + " utime: %d.%06d s (+ %d.%06d s) <- 子プロセス2秒、孫プロセス1秒の和", (cur_utime / ONE_SEC), (cur_utime % ONE_SEC), (delta_utime / ONE_SEC), (delta_utime % ONE_SEC)); OKNG(cur_stime < (1.9 * ONE_SEC) || delta_stime > (2.1 * ONE_SEC), - " stime: %d.%06d s (+ %d.%06d s)", + " stime: %d.%06d s (+ %d.%06d s) <- 子プロセス1秒、孫プロセス1秒の和", (cur_stime / ONE_SEC), (cur_stime % ONE_SEC), (delta_stime / ONE_SEC), (delta_stime % ONE_SEC)); OKNG(cur_maxrss < 32 * 1024 || cur_maxrss > 40 * 1024, - " maxrss: %d KB (+ %d KB)", cur_maxrss, delta_maxrss); + " maxrss: %d KB (+ %d KB) <- 子、孫のmaxrssの最大値", + cur_maxrss, delta_maxrss); prev_utime = cur_utime; prev_stime = cur_stime; diff --git a/test/mng_mod/issues/1032-34/CT_009.c b/test/mng_mod/issues/1032-34/CT_009.c index 516f52af..50f07407 100644 --- a/test/mng_mod/issues/1032-34/CT_009.c +++ b/test/mng_mod/issues/1032-34/CT_009.c @@ -126,7 +126,7 @@ int main(int argc, char* argv[]) (cur_utime / ONE_SEC), (cur_utime % ONE_SEC), (delta_utime / ONE_SEC), (delta_utime % ONE_SEC)); OKNG(delta_stime < (2.9 * ONE_SEC) || delta_stime > (3.1 * ONE_SEC), - " stime: %d.%06d s (+ %d.%06d s)", + " stime: %d.%06d s (+ %d.%06d s) <- join待ち3秒", (cur_stime / ONE_SEC), (cur_stime % ONE_SEC), (delta_stime / ONE_SEC), (delta_stime % ONE_SEC)); diff --git a/test/mng_mod/issues/1032-34/README b/test/mng_mod/issues/1032-34/README index 69a5384b..f8890487 100644 --- a/test/mng_mod/issues/1032-34/README +++ b/test/mng_mod/issues/1032-34/README @@ -4,13 +4,14 @@ McKernelでのgetrusage()の基本動作確認（10項目）の計13項目のテ なお、各テストの実行結果は./result.log として格納している。 ①Issueで報告されたテストプログラムによる確認 - ・Issue#1032 + ・Issue#1032, Issue#1033, Issue#1034 報告で使用されたテストプログラムを100回ずつ実行し、現象が再現しないことを確認した。 - 実行時の出力の1回分を./result.log に記載している + 実行時の出力の1回分を./result.log に記載している。 ②McKernelでのgetrusage()の基本動作確認 以下の内容で、Issue#1032～#1034による変更が既存機能に影響しないことを確認した。 各項目はそれぞれ100回ずつ実行し、すべてでPASSすることを確認した。 +テストプログラムの1回分の実行結果をresult.log に記載している。 基本動作確認の詳細を以下に示す。 @@ -22,7 +23,14 @@ McKernelでのgetrusage()の基本動作確認（10項目）の計13項目のテ 4. sh make test を実行する 5. ./rm_test_driver.sh を実行し、テスト用のデバイスドライバをアンロードする -2. テスト項目 +2. 前提 + テスト中でのCPU時間の加算処理は以下のようにして行っている。 + utime：alarm(2)とSIGALRMハンドラを用いて、SIGALRM受信をcpu_pause()で待つ + stime：テスト用のデバイスドライバファイル(/dev/test_rusage) へのioctl発行 + 上記ioctlはrequest番号秒だけシステム内で処理を行う + (Linuxでの実行時はタスクがスイッチされるため想定通りの結果は得られない) + +3. テスト項目 CT_001: 単一プロセスでのRUSAGE_SELFの utime, stime計測動作 観点：自プロセスのutime, stime計測を確認する 1. getrusage(RUSAGE_SELF) を実行し、以下を確認 @@ -184,6 +192,3 @@ CT_010: サブスレッド作成時のRUSAGE_THREAD のmaxrss計測 4. メインスレッドがgetrusage(RUSAGE_THREAD) を実行し、以下を確認 - maxrssの値が 16MB 以上 -3. 結果 -テストプログラムの1回分の実行結果をresult.log に示す。 -上記の項目がすべてPASSしていることを確認した。 diff --git a/test/mng_mod/issues/1032-34/result.log b/test/mng_mod/issues/1032-34/result.log index 22223d7a..fdb2919d 100644 --- a/test/mng_mod/issues/1032-34/result.log +++ b/test/mng_mod/issues/1032-34/result.log @@ -49,7 +49,7 @@ show_rusage(): ------------------------------ RESULT: you need check rusage value -$ mcexec ./test_mck -s getrusage -n 1 +$ mcexec ./test_mck -s getrusage -n 2 TEST_SUITE: getrusage TEST_NUMBER: 2 ARGS: @@ -91,72 +91,77 @@ RESULT: you need check rusage value /home/satoken/ppos/bin/mcexec ./CT_001 ---- just started ---- [ RUSAGE_SELF ] - [OK] utime: 0.000526 s (+ 0.000526 s) - [OK] stime: 0.010256 s (+ 0.010256 s) + [OK] utime: 0.000528 s (+ 0.000528 s) + [OK] stime: 0.010448 s (+ 0.010448 s) ---- add utime 2sec ---- [ RUSAGE_SELF ] - [OK] utime: 1.997451 s (+ 1.996925 s) - [OK] stime: 0.010382 s (+ 0.000126 s) + [OK] utime: 1.997452 s (+ 1.996924 s) + [OK] stime: 0.010633 s (+ 0.000185 s) ---- add stime 1sec ---- [ RUSAGE_SELF ] - [OK] utime: 1.997458 s (+ 0.000007 s) - [OK] stime: 1.008919 s (+ 0.998537 s) + [OK] utime: 1.997459 s (+ 0.000007 s) + [OK] stime: 1.009232 s (+ 0.998599 s) *** CT_001 PASS /home/satoken/ppos/bin/mcexec ./CT_002 ---- just started ---- [ RUSAGE_SELF ] - [OK] maxrss: 6016 KB (+ 6016 KB) + [OK] maxrss: 6012 KB (+ 6012 KB) ---- mmap and access 12MB (12288 KB) ---- [ RUSAGE_SELF ] - [OK] maxrss: 18356 KB (+ 12340 KB) + [OK] maxrss: 18352 KB (+ 12340 KB) ---- munmap 12MB (12288 KB) ---- [ RUSAGE_SELF ] - [OK] maxrss: 18356 KB (+ 0 KB) + [OK] maxrss: 18352 KB (+ 0 KB) ---- mmap and access 16MB (16384 KB) ---- [ RUSAGE_SELF ] - [OK] maxrss: 22452 KB (+ 4096 KB) + [OK] maxrss: 22448 KB (+ 4096 KB) *** CT_002 PASS /home/satoken/ppos/bin/mcexec ./CT_003 ---- just started ---- [ RUSAGE_SELF ] - [OK] utime: 0.000528 s (+ 0.000528 s) - [OK] stime: 0.010259 s (+ 0.010259 s) + [OK] utime: 0.000530 s (+ 0.000530 s) + [OK] stime: 0.010266 s (+ 0.010266 s) ---- create thread and join ---- ---- add utime 2sec in sub thread ---- ---- add stime 1sec in sub thread ---- ---- sub thread exit ---- [ RUSAGE_SELF ] - [OK] utime: 1.997488 s (+ 1.996960 s) - [OK] stime: 4.005689 s (+ 3.995430 s) + [OK] utime: 1.997492 s (+ 1.996962 s) <- サブスレッド増分2秒 + [OK] stime: 4.005857 s (+ 3.995591 s) <- サブスレッド増分1秒 + メインスレッドjoin待ち3秒 *** CT_003 PASS /home/satoken/ppos/bin/mcexec ./CT_004 ---- just started ---- [ RUSAGE_SELF ] - [OK] maxrss: 6012 KB (+ 6012 KB) + [OK] maxrss: 6008 KB (+ 6008 KB) ---- create thread and join ---- ---- mmap and access 16MB (16384 KB) in sub thread ---- ---- munmap 16MB (16384 KB) in sub thread ---- ---- sub thread exit ---- [ RUSAGE_SELF ] - [OK] maxrss: 30652 KB (+ 24640 KB) + [OK] maxrss: 30652 KB (+ 24644 KB) *** CT_004 PASS /home/satoken/ppos/bin/mcexec ./CT_005 ---- just started ---- [ RUSAGE_SELF ] - [OK] utime: 0.000520 s (+ 0.000520 s) - [OK] stime: 0.010293 s (+ 0.010293 s) - [OK] maxrss: 6016 KB (+ 6016 KB) + [OK] utime: 0.000522 s (+ 0.000522 s) + [OK] stime: 0.010163 s (+ 0.010163 s) + [OK] maxrss: 6012 KB (+ 6012 KB) ---- fork child process ---- ---- add utime 3sec in parent ---- + ---- add utime 1sec in child ---- + ---- add stime 1sec in child ---- + ---- mmap and access 16MB (16384 KB) in child ---- + ---- munmap 16MB (16384 KB) in child ---- + ---- child process exit ---- ---- wait child's exit ---- [ RUSAGE_SELF ] - [OK] utime: 2.995897 s (+ 2.995377 s) - [OK] stime: 0.015820 s (+ 0.005527 s) - [OK] maxrss: 6088 KB (+ 72 KB) + [OK] utime: 2.995901 s (+ 2.995379 s) + [OK] stime: 0.016541 s (+ 0.006378 s) + [OK] maxrss: 6084 KB (+ 72 KB) *** CT_005 PASS /home/satoken/ppos/bin/mcexec ./CT_006 @@ -166,13 +171,16 @@ RESULT: you need check rusage value [OK] stime: 0.000000 s (+ 0.000000 s) ---- fork child process ---- ---- add utime 1sec in parent ---- + ---- add utime 2sec in child ---- [ RUSAGE_CHILDREN ] - [OK] utime: 0.000000 s (+ 0.000000 s) - [OK] stime: 0.000000 s (+ 0.000000 s) + [OK] utime: 0.000000 s (+ 0.000000 s) <- 子プロセスが未終了のため、0 + [OK] stime: 0.000000 s (+ 0.000000 s) <- 子プロセスが未終了のため、0 ---- wait child's exit ---- + ---- add stime 1sec in child ---- + ---- child process exit ---- [ RUSAGE_CHILDREN ] - [OK] utime: 1.996942 s (+ 1.996942 s) - [OK] stime: 0.998600 s (+ 0.998600 s) + [OK] utime: 1.996946 s (+ 1.996946 s) + [OK] stime: 0.998663 s (+ 0.998663 s) *** CT_006 PASS /home/satoken/ppos/bin/mcexec ./CT_007 @@ -181,10 +189,14 @@ RESULT: you need check rusage value [OK] maxrss: 0 KB (+ 0 KB) ---- fork child process ---- ---- mmap and access 32MB (32768 KB) in parent ---- + ---- add utime 1sec in child ---- ---- munmap 32MB (32768 KB) in parent ---- ---- wait child's exit ---- + ---- mmap and access 16MB (16384 KB) in child ---- + ---- munmap 16MB (16384 KB) in child ---- + ---- child process exit ---- [ RUSAGE_CHILDREN ] - [OK] maxrss: 21520 KB (+ 21520 KB) + [OK] maxrss: 21516 KB (+ 21516 KB) <- 子プロセス終了後に更新される *** CT_007 PASS /home/satoken/ppos/bin/mcexec ./CT_008 @@ -195,45 +207,56 @@ RESULT: you need check rusage value [OK] maxrss: 0 KB (+ 0 KB) ---- fork child process ---- ---- wait child's exit ---- + ---- fork mago process ---- + ---- add utime 2sec in child ---- + ---- add utime 1sec in mago ---- + ---- add stime 1sec in mago ---- + ---- add stime 1sec in child ---- + ---- mmap and access 32MB (32768 KB) in mago ---- + ---- munmap 32MB (32768 KB) in mago ---- + ---- mago process exit ---- + ---- mmap and access 8MB (8192 KB) in child ---- + ---- munmap 8MB (8192 KB) in child ---- + ---- wait mago's exit ---- + ---- child process exit ---- [ RUSAGE_CHILDREN ] - [OK] utime: 2.999739 s (+ 2.999739 s) - [OK] stime: 2.009159 s (+ 2.009159 s) - [OK] maxrss: 37900 KB (+ 37900 KB) + [OK] utime: 2.999763 s (+ 2.999763 s) <- 子プロセス2秒、孫プロセス1秒の和 + [OK] stime: 2.009389 s (+ 2.009389 s) <- 子プロセス1秒、孫プロセス1秒の和 + [OK] maxrss: 37896 KB (+ 37896 KB) <- 子、孫のmaxrssの最大値 *** CT_008 PASS /home/satoken/ppos/bin/mcexec ./CT_009 ---- just started ---- - [OK] utime: 0.000533 s (+ 0.000533 s) - [OK] stime: 0.010117 s (+ 0.010117 s) + [OK] utime: 0.000535 s (+ 0.000535 s) + [OK] stime: 0.009965 s (+ 0.009965 s) ---- add utime 1sec in main thread ---- ---- create thread and join ---- [ RUSAGE_THREAD ] [OK] utime: 0.000005 s (+ 0.000005 s) - [OK] stime: 0.000015 s (+ 0.000015 s) + [OK] stime: 0.000014 s (+ 0.000014 s) ---- add utime 2sec in sub thread ---- ---- add stime 1sec in sub thread ---- [ RUSAGE_THREAD ] - [OK] utime: 1.996923 s (+ 1.996923 s) - [OK] stime: 0.998568 s (+ 0.998568 s) + [OK] utime: 1.996925 s (+ 1.996925 s) + [OK] stime: 0.998649 s (+ 0.998649 s) ---- sub thread exit ---- [ RUSAGE_THREAD ] - [OK] utime: 0.999024 s (+ 0.998491 s) - [OK] stime: 3.007089 s (+ 2.996972 s) + [OK] utime: 0.999027 s (+ 0.998492 s) + [OK] stime: 3.006955 s (+ 2.996990 s) <- join待ち3秒 *** CT_009 PASS /home/satoken/ppos/bin/mcexec ./CT_010 ---- just started ---- [ RUSAGE_THREAD ] - [OK] maxrss: 6012 KB (+ 6012 KB) + [OK] maxrss: 6008 KB (+ 6008 KB) ---- mmap and access 8MB (8192 KB) in main thread ---- ---- munmap 8MB (8192 KB) in main thread ---- ---- create and join thread ---- [ RUSAGE_THREAD ] - [OK] maxrss: 14268 KB + [OK] maxrss: 14264 KB ---- mmap and access 16MB (16384 KB) in sub thread ---- ---- munmap 16MB (16384 KB) in sub thread ---- ---- sub thread exit ---- [ RUSAGE_THREAD ] - [OK] maxrss: 30652 KB (+ 24640 KB) + [OK] maxrss: 30652 KB (+ 24644 KB) *** CT_010 PASS -