* [LTP] [PATCH] Make getrusage04 be able to loop more times
@ 2017-06-02 7:28 Chunyu Hu
2017-06-07 15:13 ` Cyril Hrubis
0 siblings, 1 reply; 6+ messages in thread
From: Chunyu Hu @ 2017-06-02 7:28 UTC (permalink / raw)
To: ltp
The -i or -I will break when the tv_usec of timeval gets to
1000000, so usually we can't loop for too many times with -i
or -I. Approximately 1000 times loop will break with a false
positive failure:
getrusage04 0 TINFO : utime: 53636us; stime: 989510us
getrusage04 0 TINFO : utime: 53682us; stime: 999301us
getrusage04 0 TINFO : utime: 53718us; stime: 8906us
getrusage04 1 TFAIL : getrusage04.c:133: stime increased > 11000us:
Sometimes we need to run more than one second user/sys time,
here consider the carry-over to timeval.tv_sec when timeval.tv_usec
gets overflow, and print out the second info of utime and stime for
providing needed test info.
Also fix warn casused by the var types with '-Wsign-compare'
getrusage04.c:121:16: warning: comparison between signed and...
if (udelta > 1000 + (BIAS_MAX * factor_nr)) {
Signed-off-by: Chunyu Hu <chuhu@redhat.com>
---
testcases/kernel/syscalls/getrusage/getrusage04.c | 24 +++++++++++++++--------
1 file changed, 16 insertions(+), 8 deletions(-)
diff --git a/testcases/kernel/syscalls/getrusage/getrusage04.c b/testcases/kernel/syscalls/getrusage/getrusage04.c
index a5b3f65..6b36cec 100644
--- a/testcases/kernel/syscalls/getrusage/getrusage04.c
+++ b/testcases/kernel/syscalls/getrusage/getrusage04.c
@@ -82,7 +82,8 @@ static void cleanup(void);
int main(int argc, char *argv[])
{
struct rusage usage;
- unsigned long ulast, udelta, slast, sdelta;
+ unsigned long ulast, slast, ulasts, slasts;
+ long udelta, sdelta, udeltas, sdeltas;
int i, lc;
char msg_string[BUFSIZ];
@@ -104,28 +105,33 @@ int main(int argc, char *argv[])
tst_count = 0;
i = 0;
SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage);
- tst_resm(TINFO, "utime:%12luus; stime:%12luus",
- usage.ru_utime.tv_usec, usage.ru_stime.tv_usec);
+ tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus",
+ usage.ru_utime.tv_sec, usage.ru_utime.tv_usec,
+ usage.ru_stime.tv_sec, usage.ru_stime.tv_usec);
ulast = usage.ru_utime.tv_usec;
slast = usage.ru_stime.tv_usec;
+ ulasts = usage.ru_utime.tv_sec;
+ slasts = usage.ru_stime.tv_sec;
while (i < RECORD_MAX) {
SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage);
udelta = usage.ru_utime.tv_usec - ulast;
sdelta = usage.ru_stime.tv_usec - slast;
+ udeltas = usage.ru_utime.tv_sec - ulasts;
+ sdeltas = usage.ru_stime.tv_sec - slasts;
if (udelta > 0 || sdelta > 0) {
i++;
- tst_resm(TINFO, "utime:%12luus; stime:%12luus",
- usage.ru_utime.tv_usec,
- usage.ru_stime.tv_usec);
- if (udelta > 1000 + (BIAS_MAX * factor_nr)) {
+ tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus",
+ usage.ru_utime.tv_sec, usage.ru_utime.tv_usec,
+ usage.ru_stime.tv_sec, usage.ru_stime.tv_usec);
+ if (udelta > 1000 + (BIAS_MAX * factor_nr) && !udeltas) {
sprintf(msg_string,
"utime increased > %ldus:",
1000 + BIAS_MAX * factor_nr);
tst_brkm(TFAIL, cleanup, msg_string,
" delta = %luus", udelta);
}
- if (sdelta > 1000 + (BIAS_MAX * factor_nr)) {
+ if (sdelta > 1000 + (BIAS_MAX * factor_nr) && !sdeltas) {
sprintf(msg_string,
"stime increased > %ldus:",
1000 + BIAS_MAX * factor_nr);
@@ -135,6 +141,8 @@ int main(int argc, char *argv[])
}
ulast = usage.ru_utime.tv_usec;
slast = usage.ru_stime.tv_usec;
+ ulasts = usage.ru_utime.tv_sec;
+ slasts = usage.ru_stime.tv_sec;
busyloop(100000);
}
}
--
1.8.3.1
^ permalink raw reply related [flat|nested] 6+ messages in thread* [LTP] [PATCH] Make getrusage04 be able to loop more times 2017-06-02 7:28 [LTP] [PATCH] Make getrusage04 be able to loop more times Chunyu Hu @ 2017-06-07 15:13 ` Cyril Hrubis 2017-06-09 7:42 ` Chunyu Hu 0 siblings, 1 reply; 6+ messages in thread From: Cyril Hrubis @ 2017-06-07 15:13 UTC (permalink / raw) To: ltp Hi! > int main(int argc, char *argv[]) > { > struct rusage usage; > - unsigned long ulast, udelta, slast, sdelta; > + unsigned long ulast, slast, ulasts, slasts; > + long udelta, sdelta, udeltas, sdeltas; > int i, lc; > char msg_string[BUFSIZ]; > > @@ -104,28 +105,33 @@ int main(int argc, char *argv[]) > tst_count = 0; > i = 0; > SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); > - tst_resm(TINFO, "utime:%12luus; stime:%12luus", > - usage.ru_utime.tv_usec, usage.ru_stime.tv_usec); > + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", > + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, > + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); > ulast = usage.ru_utime.tv_usec; > slast = usage.ru_stime.tv_usec; > + ulasts = usage.ru_utime.tv_sec; > + slasts = usage.ru_stime.tv_sec; This is getting ugly. Why not just: struct timeval ulast = usage.ru_utime; struct timeval slast = usage.ru_stime; > while (i < RECORD_MAX) { > SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); > udelta = usage.ru_utime.tv_usec - ulast; > sdelta = usage.ru_stime.tv_usec - slast; > + udeltas = usage.ru_utime.tv_sec - ulasts; > + sdeltas = usage.ru_stime.tv_sec - slasts; > if (udelta > 0 || sdelta > 0) { > i++; > - tst_resm(TINFO, "utime:%12luus; stime:%12luus", > - usage.ru_utime.tv_usec, > - usage.ru_stime.tv_usec); > - if (udelta > 1000 + (BIAS_MAX * factor_nr)) { > + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", > + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, > + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); > + if (udelta > 1000 + (BIAS_MAX * factor_nr) && !udeltas) { > sprintf(msg_string, > "utime increased > %ldus:", > 1000 + BIAS_MAX * factor_nr); > tst_brkm(TFAIL, cleanup, msg_string, > " delta = %luus", udelta); > } > - if (sdelta > 1000 + (BIAS_MAX * factor_nr)) { > + if (sdelta > 1000 + (BIAS_MAX * factor_nr) && !sdeltas) { Also why do we skipp the comparsion if seconds has changed? Computing difference for twom timeval structures is not that complicated. I can add a helper into include/tst_timer.h if you want. > sprintf(msg_string, > "stime increased > %ldus:", > 1000 + BIAS_MAX * factor_nr); > @@ -135,6 +141,8 @@ int main(int argc, char *argv[]) > } > ulast = usage.ru_utime.tv_usec; > slast = usage.ru_stime.tv_usec; > + ulasts = usage.ru_utime.tv_sec; > + slasts = usage.ru_stime.tv_sec; > busyloop(100000); > } > } > -- > 1.8.3.1 > > > -- > Mailing list info: https://lists.linux.it/listinfo/ltp -- Cyril Hrubis chrubis@suse.cz ^ permalink raw reply [flat|nested] 6+ messages in thread
* [LTP] [PATCH] Make getrusage04 be able to loop more times 2017-06-07 15:13 ` Cyril Hrubis @ 2017-06-09 7:42 ` Chunyu Hu 2017-06-12 15:04 ` Cyril Hrubis 0 siblings, 1 reply; 6+ messages in thread From: Chunyu Hu @ 2017-06-09 7:42 UTC (permalink / raw) To: ltp ----- Original Message ----- > From: "Cyril Hrubis" <chrubis@suse.cz> > To: "Chunyu Hu" <chuhu@redhat.com> > Cc: ltp@lists.linux.it > Sent: Wednesday, June 7, 2017 11:13:15 PM > Subject: Re: [LTP] [PATCH] Make getrusage04 be able to loop more times > > Hi! > > int main(int argc, char *argv[]) > > { > > struct rusage usage; > > - unsigned long ulast, udelta, slast, sdelta; > > + unsigned long ulast, slast, ulasts, slasts; > > + long udelta, sdelta, udeltas, sdeltas; > > int i, lc; > > char msg_string[BUFSIZ]; > > > > @@ -104,28 +105,33 @@ int main(int argc, char *argv[]) > > tst_count = 0; > > i = 0; > > SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); > > - tst_resm(TINFO, "utime:%12luus; stime:%12luus", > > - usage.ru_utime.tv_usec, usage.ru_stime.tv_usec); > > + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", > > + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, > > + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); > > ulast = usage.ru_utime.tv_usec; > > slast = usage.ru_stime.tv_usec; > > + ulasts = usage.ru_utime.tv_sec; > > + slasts = usage.ru_stime.tv_sec; > > This is getting ugly. Why not just: > > struct timeval ulast = usage.ru_utime; > struct timeval slast = usage.ru_stime; OK. I'll post a V2 for this. > > > > while (i < RECORD_MAX) { > > SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); > > udelta = usage.ru_utime.tv_usec - ulast; > > sdelta = usage.ru_stime.tv_usec - slast; > > + udeltas = usage.ru_utime.tv_sec - ulasts; > > + sdeltas = usage.ru_stime.tv_sec - slasts; > > if (udelta > 0 || sdelta > 0) { > > i++; > > - tst_resm(TINFO, "utime:%12luus; stime:%12luus", > > - usage.ru_utime.tv_usec, > > - usage.ru_stime.tv_usec); > > - if (udelta > 1000 + (BIAS_MAX * factor_nr)) { > > + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", > > + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, > > + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); > > + if (udelta > 1000 + (BIAS_MAX * factor_nr) && !udeltas) { > > sprintf(msg_string, > > "utime increased > %ldus:", > > 1000 + BIAS_MAX * factor_nr); > > tst_brkm(TFAIL, cleanup, msg_string, > > " delta = %luus", udelta); > > } > > - if (sdelta > 1000 + (BIAS_MAX * factor_nr)) { > > + if (sdelta > 1000 + (BIAS_MAX * factor_nr) && !sdeltas) { > > Also why do we skipp the comparsion if seconds has changed? OK. I'll try to consider second info in V2. > > Computing difference for twom timeval structures is not that > complicated. I can add a helper into include/tst_timer.h if you want. Do we have? I think we need something like below, not clear about if this can be done with function or macro ;). timval_minus(tv1, tv2) and timeval_gt timeval_lt timeval_e > > > sprintf(msg_string, > > "stime increased > %ldus:", > > 1000 + BIAS_MAX * factor_nr); > > @@ -135,6 +141,8 @@ int main(int argc, char *argv[]) > > } > > ulast = usage.ru_utime.tv_usec; > > slast = usage.ru_stime.tv_usec; > > + ulasts = usage.ru_utime.tv_sec; > > + slasts = usage.ru_stime.tv_sec; > > busyloop(100000); > > } > > } > > -- > > 1.8.3.1 > > > > > > -- > > Mailing list info: https://lists.linux.it/listinfo/ltp > > -- > Cyril Hrubis > chrubis@suse.cz > -- Regards, Chunyu Hu ^ permalink raw reply [flat|nested] 6+ messages in thread
* [LTP] [PATCH] Make getrusage04 be able to loop more times 2017-06-09 7:42 ` Chunyu Hu @ 2017-06-12 15:04 ` Cyril Hrubis 2017-06-13 11:47 ` Chunyu Hu 0 siblings, 1 reply; 6+ messages in thread From: Cyril Hrubis @ 2017-06-12 15:04 UTC (permalink / raw) To: ltp Hi! > Do we have? I think we need something like below, not clear > about if this can be done with function or macro ;). > > timval_minus(tv1, tv2) > and > timeval_gt > timeval_lt > timeval_e We only need to add tst_timeval_diff_us() into tst_timer.h then we can compare the resulting values in microsenconds. Which would mean adding tst_timeval_to_us() and tst_timeval_diff(), then adding the tst_timeval_diff_us() that combines these two. It should be staturated difference though, i.e. the conversion from timeval to microseconds should return LONG_LONG_MAX in a case that the end result would overflow long long. As I said I can add these into the tst_timer.h, and also fix the timespec to us and ms conversions to be saturated. -- Cyril Hrubis chrubis@suse.cz ^ permalink raw reply [flat|nested] 6+ messages in thread
* [LTP] [PATCH] Make getrusage04 be able to loop more times 2017-06-12 15:04 ` Cyril Hrubis @ 2017-06-13 11:47 ` Chunyu Hu 2017-06-13 12:58 ` Cyril Hrubis 0 siblings, 1 reply; 6+ messages in thread From: Chunyu Hu @ 2017-06-13 11:47 UTC (permalink / raw) To: ltp ----- Original Message ----- > From: "Cyril Hrubis" <chrubis@suse.cz> > To: "Chunyu Hu" <chuhu@redhat.com> > Cc: ltp@lists.linux.it > Sent: Monday, June 12, 2017 11:04:23 PM > Subject: Re: [LTP] [PATCH] Make getrusage04 be able to loop more times > > Hi! > > Do we have? I think we need something like below, not clear > > about if this can be done with function or macro ;). > > > > timval_minus(tv1, tv2) > > and > > timeval_gt > > timeval_lt > > timeval_e > > We only need to add tst_timeval_diff_us() into tst_timer.h then we can > compare the resulting values in microsenconds. Which would mean adding > tst_timeval_to_us() and tst_timeval_diff(), then adding the > tst_timeval_diff_us() that combines these two. This really sounds simpler than compare with timeval directly. But compare with timeval directly would make it more difficult to overflow. > > It should be staturated difference though, i.e. the conversion from > timeval to microseconds should return LONG_LONG_MAX in a case that the > end result would overflow long long. That makes sense. But how long would it overflow once? >>> print "%d" % 0xffffffffffffffff 18446744073709551615 >>> print 18446744073709551615 / 1000000 18446744073709 >>> print "%d" % 0xffffffff 4294967295 >>> print 4294967295 / 1000000 4294 > > As I said I can add these into the tst_timer.h, and also fix the > timespec to us and ms conversions to be saturated. OK. Thanks. I'll wait for your helpers before I submit a v2 for the test case. In fact, I use the test case to reproduce an issue of getrusage on rhel-7.3 which needs about 60s. getrusage04 0 TINFO : utime:6s 825358us; stime:38s 286683us getrusage04 0 TINFO : utime:6s 825358us; stime:38s 287683us getrusage04 0 TINFO : utime:6s 825358us; stime:38s 288683us getrusage04 0 TINFO : utime:6s 825358us; stime:38s 288745us getrusage04 0 TINFO : utime:6s 825362us; stime:38s 288763us getrusage04 0 TINFO : utime:6s 825365us; stime:38s 290782us getrusage04 1 TFAIL : getrusage04.c:195: stime increased > 2000us: And I tried with comparing with timeval directly, I paste it here just hoping it can provide a little idea.( just for fun) :) diff --git a/testcases/kernel/syscalls/getrusage/getrusage04.c b/testcases/kernel/syscalls/getrusage/getrusage04.c index a5b3f65..583b6ea 100644 --- a/testcases/kernel/syscalls/getrusage/getrusage04.c +++ b/testcases/kernel/syscalls/getrusage/getrusage04.c @@ -79,10 +79,65 @@ static void busyloop(long wait); static void setup(void); static void cleanup(void); +#ifndef bool + #define bool int + #ifndef false + #define false 0 + #endif + #ifndef true + #define true 1 + #endif +#endif + +static inline struct timeval timeval_minus(struct timeval t1, struct timeval t2) +{ + struct timeval result; + result.tv_sec = t1.tv_sec - t2.tv_sec; + + result.tv_usec = t1.tv_usec >= t2.tv_usec ? + (t1.tv_usec - t2.tv_usec) : + result.tv_sec > 0 ? + (result.tv_sec--,t1.tv_usec + 1000000) - t2.tv_usec: + t1.tv_usec - t2.tv_usec; + return result; +} + +static inline bool timeval_cmp_gt(struct timeval t1, struct timeval t2) +{ + return t1.tv_sec > t2.tv_sec ? + true : t1.tv_sec < t2.tv_sec ? + false : t1.tv_usec > t2.tv_usec; +} + +struct timeval mk_timeval(long long sec, long long usec) +{ + struct timeval t = {0}; + t.tv_sec = sec; + t.tv_sec += usec / 1000000; + t.tv_usec = usec % 1000000; + return t; +} + +#define TIMEVAL_POSITIVE(tv) \ +({ \ + int r; \ + r = (tv.tv_sec >= 0 && tv.tv_usec > 0); \ + r; \ +}) + + +#define TIMEVAL_NON_NEGATIVE(tv) \ +({ \ + int r; \ + r = (tv.tv_sec >= 0 && tv.tv_usec >= 0); \ + r; \ + }) + int main(int argc, char *argv[]) { struct rusage usage; - unsigned long ulast, udelta, slast, sdelta; + struct timeval ulast, slast; + struct timeval udelta, sdelta; int i, lc; char msg_string[BUFSIZ]; @@ -104,28 +159,32 @@ int main(int argc, char *argv[]) tst_count = 0; i = 0; SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); - tst_resm(TINFO, "utime:%12luus; stime:%12luus", - usage.ru_utime.tv_usec, usage.ru_stime.tv_usec); - ulast = usage.ru_utime.tv_usec; - slast = usage.ru_stime.tv_usec; + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); + + ulast = usage.ru_utime; + slast = usage.ru_stime; while (i < RECORD_MAX) { SAFE_GETRUSAGE(cleanup, RUSAGE_THREAD, &usage); - udelta = usage.ru_utime.tv_usec - ulast; - sdelta = usage.ru_stime.tv_usec - slast; - if (udelta > 0 || sdelta > 0) { + udelta = timeval_minus(usage.ru_utime, ulast); + sdelta = timeval_minus(usage.ru_stime, slast); + if (TIMEVAL_POSITIVE(udelta) || TIMEVAL_POSITIVE(sdelta)) { i++; - tst_resm(TINFO, "utime:%12luus; stime:%12luus", - usage.ru_utime.tv_usec, - usage.ru_stime.tv_usec); - if (udelta > 1000 + (BIAS_MAX * factor_nr)) { + tst_resm(TINFO, "utime:%lus %12luus; stime:%lus %12luus", + usage.ru_utime.tv_sec, usage.ru_utime.tv_usec, + usage.ru_stime.tv_sec, usage.ru_stime.tv_usec); + if (timeval_cmp_gt(udelta, + mk_timeval(0, 1000 + (BIAS_MAX * factor_nr)))) { sprintf(msg_string, "utime increased > %ldus:", 1000 + BIAS_MAX * factor_nr); tst_brkm(TFAIL, cleanup, msg_string, " delta = %luus", udelta); } - if (sdelta > 1000 + (BIAS_MAX * factor_nr)) { + if (timeval_cmp_gt(sdelta, + mk_timeval(0, 1000 + (BIAS_MAX * factor_nr)))) { sprintf(msg_string, "stime increased > %ldus:", 1000 + BIAS_MAX * factor_nr); @@ -133,8 +192,8 @@ int main(int argc, char *argv[]) " delta = %luus", sdelta); } } - ulast = usage.ru_utime.tv_usec; - slast = usage.ru_stime.tv_usec; + ulast = usage.ru_utime; + slast = usage.ru_stime; busyloop(100000); } } -- 1.8.3.1 > > -- > Cyril Hrubis > chrubis@suse.cz > -- Regards, Chunyu Hu ^ permalink raw reply related [flat|nested] 6+ messages in thread
* [LTP] [PATCH] Make getrusage04 be able to loop more times 2017-06-13 11:47 ` Chunyu Hu @ 2017-06-13 12:58 ` Cyril Hrubis 0 siblings, 0 replies; 6+ messages in thread From: Cyril Hrubis @ 2017-06-13 12:58 UTC (permalink / raw) To: ltp Hi! > > We only need to add tst_timeval_diff_us() into tst_timer.h then we can > > compare the resulting values in microsenconds. Which would mean adding > > tst_timeval_to_us() and tst_timeval_diff(), then adding the > > tst_timeval_diff_us() that combines these two. > > This really sounds simpler than compare with timeval directly. But compare > with timeval directly would make it more difficult to overflow. > > > > > It should be staturated difference though, i.e. the conversion from > > timeval to microseconds should return LONG_LONG_MAX in a case that the > > end result would overflow long long. > > That makes sense. But how long would it overflow once? > > >>> print "%d" % 0xffffffffffffffff > 18446744073709551615 > >>> print 18446744073709551615 / 1000000 > 18446744073709 > >>> print "%d" % 0xffffffff > 4294967295 > >>> print 4294967295 / 1000000 > 4294 The time_t in struct timespec and struct timeval are 64bit types on 64bit architectures, hence we can overflow 64 bit long long in a case that the difference between two tv_sec is greater than LLONG_MAX/1000000. It's extremly unlikely but may happen for instance if the structures are overwritten with random mess for some reason. -- Cyril Hrubis chrubis@suse.cz ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2017-06-13 12:58 UTC | newest] Thread overview: 6+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2017-06-02 7:28 [LTP] [PATCH] Make getrusage04 be able to loop more times Chunyu Hu 2017-06-07 15:13 ` Cyril Hrubis 2017-06-09 7:42 ` Chunyu Hu 2017-06-12 15:04 ` Cyril Hrubis 2017-06-13 11:47 ` Chunyu Hu 2017-06-13 12:58 ` Cyril Hrubis
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox