Thx for the fix!
Acked-by: Alex Wang <al...@nicira.com>
On Wed, Feb 11, 2015 at 2:54 PM, Ben Pfaff <b...@nicira.com> wrote:
> Most of the information that timeval was reporting for long poll intervals
> was comparing per-thread with per-process statistics, which yielded
> nonsense a lot of the time.
>
> Signed-off-by: Ben Pfaff <b...@nicira.com>
> ---
> v1->v2: Really fix the whole problem (thanks Alex!)
> v2->v2.1: Repost now that the list is back up.
>
> lib/timeval.c | 57
> +++++++++++++++++++++++++++++++--------------------------
> 1 file changed, 31 insertions(+), 26 deletions(-)
>
> diff --git a/lib/timeval.c b/lib/timeval.c
> index 6173aff..a77fc61 100644
> --- a/lib/timeval.c
> +++ b/lib/timeval.c
> @@ -1,5 +1,5 @@
> /*
> - * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014 Nicira, Inc.
> + * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015 Nicira,
> Inc.
> *
> * Licensed under the Apache License, Version 2.0 (the "License");
> * you may not use this file except in compliance with the License.
> @@ -102,6 +102,7 @@ DEFINE_STATIC_PER_THREAD_DATA(long long int,
> last_wakeup, 0);
>
> static void log_poll_interval(long long int last_wakeup);
> static struct rusage *get_recent_rusage(void);
> +static int getrusage_thread(struct rusage *);
> static void refresh_rusage(void);
> static void timespec_add(struct timespec *sum,
> const struct timespec *a, const struct timespec
> *b);
> @@ -561,31 +562,35 @@ log_poll_interval(long long int last_wakeup)
> const struct rusage *last_rusage = get_recent_rusage();
> struct rusage rusage;
>
> - getrusage(RUSAGE_SELF, &rusage);
> - VLOG_WARN("Unreasonably long %lldms poll interval"
> - " (%lldms user, %lldms system)",
> - interval,
> - timeval_diff_msec(&rusage.ru_utime,
> - &last_rusage->ru_utime),
> - timeval_diff_msec(&rusage.ru_stime,
> - &last_rusage->ru_stime));
> - if (rusage.ru_minflt > last_rusage->ru_minflt
> - || rusage.ru_majflt > last_rusage->ru_majflt) {
> - VLOG_WARN("faults: %ld minor, %ld major",
> - rusage.ru_minflt - last_rusage->ru_minflt,
> - rusage.ru_majflt - last_rusage->ru_majflt);
> - }
> - if (rusage.ru_inblock > last_rusage->ru_inblock
> - || rusage.ru_oublock > last_rusage->ru_oublock) {
> - VLOG_WARN("disk: %ld reads, %ld writes",
> - rusage.ru_inblock - last_rusage->ru_inblock,
> - rusage.ru_oublock - last_rusage->ru_oublock);
> - }
> - if (rusage.ru_nvcsw > last_rusage->ru_nvcsw
> - || rusage.ru_nivcsw > last_rusage->ru_nivcsw) {
> - VLOG_WARN("context switches: %ld voluntary, %ld involuntary",
> - rusage.ru_nvcsw - last_rusage->ru_nvcsw,
> - rusage.ru_nivcsw - last_rusage->ru_nivcsw);
> + if (!getrusage_thread(&rusage)) {
> + VLOG_WARN("Unreasonably long %lldms poll interval"
> + " (%lldms user, %lldms system)",
> + interval,
> + timeval_diff_msec(&rusage.ru_utime,
> + &last_rusage->ru_utime),
> + timeval_diff_msec(&rusage.ru_stime,
> + &last_rusage->ru_stime));
> +
> + if (rusage.ru_minflt > last_rusage->ru_minflt
> + || rusage.ru_majflt > last_rusage->ru_majflt) {
> + VLOG_WARN("faults: %ld minor, %ld major",
> + rusage.ru_minflt - last_rusage->ru_minflt,
> + rusage.ru_majflt - last_rusage->ru_majflt);
> + }
> + if (rusage.ru_inblock > last_rusage->ru_inblock
> + || rusage.ru_oublock > last_rusage->ru_oublock) {
> + VLOG_WARN("disk: %ld reads, %ld writes",
> + rusage.ru_inblock - last_rusage->ru_inblock,
> + rusage.ru_oublock - last_rusage->ru_oublock);
> + }
> + if (rusage.ru_nvcsw > last_rusage->ru_nvcsw
> + || rusage.ru_nivcsw > last_rusage->ru_nivcsw) {
> + VLOG_WARN("context switches: %ld voluntary, %ld
> involuntary",
> + rusage.ru_nvcsw - last_rusage->ru_nvcsw,
> + rusage.ru_nivcsw - last_rusage->ru_nivcsw);
> + }
> + } else {
> + VLOG_WARN("Unreasonably long %lldms poll interval", interval);
> }
> coverage_log();
> }
> --
> 1.7.10.4
>
> _______________________________________________
> dev mailing list
> dev@openvswitch.org
> http://openvswitch.org/mailman/listinfo/dev
>
_______________________________________________
dev mailing list
dev@openvswitch.org
http://openvswitch.org/mailman/listinfo/dev
