mir/ovs
2
0
Fork 0
mirror of https://github.com/openvswitch/ovs synced 2025-08-30 22:05:19 +00:00
Code Issues Releases Wiki Activity

timeval: Rate-limit logging rusage information.

Browse Source 
I'd always assumed that the exponentially weighted moving average code
here was sufficient rate-limiting, but I actually encountered a
pathological case some time ago that forced this rusage information to
print once a second or so, which seems too often.

Signed-off-by: Ben Pfaff <blp@nicira.com>
This commit is contained in:
Ben Pfaff
2012-04-20 13:43:54 -07:00
parent 906bb3d008
commit c563de0e38
1 changed files with 34 additions and 29 deletions
Download Patch File Download Diff File Expand all files Collapse all files

63
lib/timeval.c
View File

@@ -463,37 +463,42 @@ log_poll_interval(long long int last_wakeup)
/* Warn if we took too much time between polls: at least 50 ms and at least
* 8X the mean interval. */
if (n_samples > 10 && interval > mean_interval * 8 && interval > 50 * 16) {
const struct rusage *last_rusage = get_recent_rusage();
struct rusage rusage;
static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 3);
getrusage(RUSAGE_SELF, &rusage);
VLOG_WARN("%lld ms poll interval (%lld ms user, %lld ms system) "
"is over %u times the weighted mean interval %u ms "
"(%u samples)",
now - last_wakeup,
timeval_diff_msec(&rusage.ru_utime, &last_rusage->ru_utime),
timeval_diff_msec(&rusage.ru_stime, &last_rusage->ru_stime),
interval / mean_interval,
(mean_interval + 8) / 16, n_samples);
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 (!VLOG_DROP_WARN(&rl)) {
const struct rusage *last_rusage = get_recent_rusage();
struct rusage rusage;
getrusage(RUSAGE_SELF, &rusage);
VLOG_WARN("%lld ms poll interval (%lld ms user, %lld ms system) "
"is over %u times the weighted mean interval %u ms "
"(%u samples)",
now - last_wakeup,
timeval_diff_msec(&rusage.ru_utime,
&last_rusage->ru_utime),
timeval_diff_msec(&rusage.ru_stime,
&last_rusage->ru_stime),
interval / mean_interval,
(mean_interval + 8) / 16, n_samples);
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);
}
}
/* Care should be taken in the value chosen for logging. Depending
* on the configuration, syslog can write changes synchronously,
* which can cause the coverage messages to take longer to log