]>
Commit | Line | Data |
---|---|---|
064af421 | 1 | /* |
653ce9d6 | 2 | * Copyright (c) 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015 Nicira, Inc. |
064af421 | 3 | * |
a14bc59f BP |
4 | * Licensed under the Apache License, Version 2.0 (the "License"); |
5 | * you may not use this file except in compliance with the License. | |
6 | * You may obtain a copy of the License at: | |
064af421 | 7 | * |
a14bc59f BP |
8 | * http://www.apache.org/licenses/LICENSE-2.0 |
9 | * | |
10 | * Unless required by applicable law or agreed to in writing, software | |
11 | * distributed under the License is distributed on an "AS IS" BASIS, | |
12 | * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | |
13 | * See the License for the specific language governing permissions and | |
14 | * limitations under the License. | |
064af421 BP |
15 | */ |
16 | ||
17 | #include <config.h> | |
18 | #include "timeval.h" | |
064af421 BP |
19 | #include <errno.h> |
20 | #include <poll.h> | |
75f9c912 | 21 | #include <pthread.h> |
064af421 | 22 | #include <signal.h> |
6197af6e | 23 | #include <stdlib.h> |
064af421 BP |
24 | #include <string.h> |
25 | #include <sys/time.h> | |
26 | #include <sys/resource.h> | |
27 | #include <unistd.h> | |
28 | #include "coverage.h" | |
6197af6e | 29 | #include "dummy.h" |
3e8a2ad1 | 30 | #include "openvswitch/dynamic-string.h" |
064af421 | 31 | #include "fatal-signal.h" |
7d1563e9 | 32 | #include "hash.h" |
ee89ea7b | 33 | #include "openvswitch/hmap.h" |
0f2ea848 | 34 | #include "ovs-rcu.h" |
728a8b14 | 35 | #include "ovs-thread.h" |
279c9e03 | 36 | #include "signals.h" |
53d98a1e | 37 | #include "seq.h" |
6197af6e | 38 | #include "unixctl.h" |
064af421 | 39 | #include "util.h" |
e6211adc | 40 | #include "openvswitch/vlog.h" |
5136ce49 | 41 | |
d98e6007 | 42 | VLOG_DEFINE_THIS_MODULE(timeval); |
064af421 | 43 | |
291716e1 | 44 | #if defined(_WIN32) || defined(__MACH__) |
48f8613f | 45 | typedef unsigned int clockid_t; |
291716e1 | 46 | static int clock_gettime(clock_t id, struct timespec *ts); |
48f8613f GS |
47 | |
48 | #ifndef CLOCK_MONOTONIC | |
49 | #define CLOCK_MONOTONIC 1 | |
50 | #endif | |
51 | ||
52 | #ifndef CLOCK_REALTIME | |
53 | #define CLOCK_REALTIME 2 | |
54 | #endif | |
291716e1 | 55 | #endif /* defined(_WIN32) || defined(__MACH__) */ |
48f8613f | 56 | |
291716e1 | 57 | #ifdef _WIN32 |
48f8613f | 58 | /* Number of 100 ns intervals from January 1, 1601 till January 1, 1970. */ |
4537a423 | 59 | const static unsigned long long unix_epoch = 116444736000000000; |
48f8613f GS |
60 | #endif /* _WIN32 */ |
61 | ||
8661af79 GS |
62 | /* Structure set by unixctl time/warp command. */ |
63 | struct large_warp { | |
64 | struct unixctl_conn *conn; /* Connection waiting for warp response. */ | |
65 | long long int total_warp; /* Total offset to be added to monotonic time. */ | |
66 | long long int warp; /* 'total_warp' offset done in steps of 'warp'. */ | |
67 | unsigned int main_thread_id; /* Identification for the main thread. */ | |
68 | }; | |
69 | ||
75f9c912 BP |
70 | struct clock { |
71 | clockid_t id; /* CLOCK_MONOTONIC or CLOCK_REALTIME. */ | |
c73814a3 | 72 | |
e6249c68 | 73 | /* Features for use by unit tests. Protected by 'mutex'. */ |
04b331cd | 74 | atomic_bool slow_path; /* True if warped or stopped. */ |
3e509ec5 | 75 | bool stopped OVS_GUARDED; /* Disable real-time updates if true. */ |
db2e457d BB |
76 | struct ovs_mutex mutex; |
77 | struct timespec warp OVS_GUARDED; /* Offset added for unit tests. */ | |
3e509ec5 | 78 | struct timespec cache OVS_GUARDED; /* Last time read from kernel. */ |
8661af79 GS |
79 | struct large_warp large_warp OVS_GUARDED; /* Connection information waiting |
80 | for warp response. */ | |
75f9c912 | 81 | }; |
064af421 | 82 | |
75f9c912 BP |
83 | /* Our clocks. */ |
84 | static struct clock monotonic_clock; /* CLOCK_MONOTONIC, if available. */ | |
85 | static struct clock wall_clock; /* CLOCK_REALTIME. */ | |
064af421 | 86 | |
4ae90ff9 BP |
87 | /* The monotonic time at which the time module was initialized. */ |
88 | static long long int boot_time; | |
89 | ||
53d98a1e AW |
90 | /* True only when timeval_dummy_register() is called. */ |
91 | static bool timewarp_enabled; | |
92 | /* Reference to the seq struct. Threads other than main thread can | |
93 | * wait on timewarp_seq and be waken up when time is warped. */ | |
94 | static struct seq *timewarp_seq; | |
95 | /* Last value of 'timewarp_seq'. */ | |
96 | DEFINE_STATIC_PER_THREAD_DATA(uint64_t, last_seq, 0); | |
97 | ||
75f9c912 BP |
98 | /* Monotonic time in milliseconds at which to die with SIGALRM (if not |
99 | * LLONG_MAX). */ | |
00a16895 | 100 | static long long int deadline = LLONG_MAX; |
064af421 | 101 | |
4c694ff7 BP |
102 | /* Monotonic time, in milliseconds, at which the last call to time_poll() woke |
103 | * up. */ | |
2ba4f163 | 104 | DEFINE_STATIC_PER_THREAD_DATA(long long int, last_wakeup, 0); |
4c694ff7 | 105 | |
959ec62e BP |
106 | static void log_poll_interval(long long int last_wakeup); |
107 | static struct rusage *get_recent_rusage(void); | |
653ce9d6 | 108 | static int getrusage_thread(struct rusage *); |
959ec62e | 109 | static void refresh_rusage(void); |
6197af6e BP |
110 | static void timespec_add(struct timespec *sum, |
111 | const struct timespec *a, const struct timespec *b); | |
7d1563e9 | 112 | |
ff8bb7e7 | 113 | static void |
75f9c912 | 114 | init_clock(struct clock *c, clockid_t id) |
064af421 | 115 | { |
75f9c912 BP |
116 | memset(c, 0, sizeof *c); |
117 | c->id = id; | |
e6249c68 | 118 | ovs_mutex_init(&c->mutex); |
04b331cd | 119 | atomic_init(&c->slow_path, false); |
75f9c912 BP |
120 | xclock_gettime(c->id, &c->cache); |
121 | } | |
9d232a6d | 122 | |
75f9c912 BP |
123 | static void |
124 | do_init_time(void) | |
125 | { | |
126 | struct timespec ts; | |
064af421 | 127 | |
f5c6854a JP |
128 | coverage_init(); |
129 | ||
33c24cf9 | 130 | timewarp_seq = seq_create(); |
75f9c912 BP |
131 | init_clock(&monotonic_clock, (!clock_gettime(CLOCK_MONOTONIC, &ts) |
132 | ? CLOCK_MONOTONIC | |
133 | : CLOCK_REALTIME)); | |
134 | init_clock(&wall_clock, CLOCK_REALTIME); | |
135 | boot_time = timespec_to_msec(&monotonic_clock.cache); | |
75f9c912 | 136 | } |
49635519 | 137 | |
75f9c912 BP |
138 | /* Initializes the timetracking module, if not already initialized. */ |
139 | static void | |
140 | time_init(void) | |
141 | { | |
142 | static pthread_once_t once = PTHREAD_ONCE_INIT; | |
143 | pthread_once(&once, do_init_time); | |
c73814a3 JG |
144 | } |
145 | ||
c73814a3 | 146 | static void |
75f9c912 | 147 | time_timespec__(struct clock *c, struct timespec *ts) |
c73814a3 | 148 | { |
04b331cd BP |
149 | bool slow_path; |
150 | ||
f54e56fc | 151 | time_init(); |
c73814a3 | 152 | |
fc4a1204 | 153 | atomic_read_relaxed(&c->slow_path, &slow_path); |
04b331cd | 154 | if (!slow_path) { |
31ef9f51 AW |
155 | xclock_gettime(c->id, ts); |
156 | } else { | |
04b331cd BP |
157 | struct timespec warp; |
158 | struct timespec cache; | |
159 | bool stopped; | |
160 | ||
e6249c68 | 161 | ovs_mutex_lock(&c->mutex); |
04b331cd BP |
162 | stopped = c->stopped; |
163 | warp = c->warp; | |
164 | cache = c->cache; | |
e6249c68 | 165 | ovs_mutex_unlock(&c->mutex); |
04b331cd BP |
166 | |
167 | if (!stopped) { | |
168 | xclock_gettime(c->id, &cache); | |
169 | } | |
170 | timespec_add(ts, &cache, &warp); | |
f802352d | 171 | } |
c73814a3 JG |
172 | } |
173 | ||
75f9c912 BP |
174 | /* Stores a monotonic timer, accurate within TIME_UPDATE_INTERVAL ms, into |
175 | * '*ts'. */ | |
064af421 | 176 | void |
75f9c912 | 177 | time_timespec(struct timespec *ts) |
064af421 | 178 | { |
75f9c912 BP |
179 | time_timespec__(&monotonic_clock, ts); |
180 | } | |
181 | ||
182 | /* Stores the current time, accurate within TIME_UPDATE_INTERVAL ms, into | |
183 | * '*ts'. */ | |
184 | void | |
185 | time_wall_timespec(struct timespec *ts) | |
186 | { | |
187 | time_timespec__(&wall_clock, ts); | |
188 | } | |
189 | ||
190 | static time_t | |
191 | time_sec__(struct clock *c) | |
192 | { | |
193 | struct timespec ts; | |
194 | ||
195 | time_timespec__(c, &ts); | |
196 | return ts.tv_sec; | |
064af421 BP |
197 | } |
198 | ||
c73814a3 | 199 | /* Returns a monotonic timer, in seconds. */ |
064af421 BP |
200 | time_t |
201 | time_now(void) | |
202 | { | |
75f9c912 | 203 | return time_sec__(&monotonic_clock); |
064af421 BP |
204 | } |
205 | ||
c73814a3 JG |
206 | /* Returns the current time, in seconds. */ |
207 | time_t | |
208 | time_wall(void) | |
209 | { | |
75f9c912 BP |
210 | return time_sec__(&wall_clock); |
211 | } | |
212 | ||
213 | static long long int | |
214 | time_msec__(struct clock *c) | |
215 | { | |
216 | struct timespec ts; | |
217 | ||
218 | time_timespec__(c, &ts); | |
219 | return timespec_to_msec(&ts); | |
c73814a3 JG |
220 | } |
221 | ||
222 | /* Returns a monotonic timer, in ms (within TIME_UPDATE_INTERVAL ms). */ | |
064af421 BP |
223 | long long int |
224 | time_msec(void) | |
225 | { | |
75f9c912 | 226 | return time_msec__(&monotonic_clock); |
c73814a3 JG |
227 | } |
228 | ||
229 | /* Returns the current time, in ms (within TIME_UPDATE_INTERVAL ms). */ | |
230 | long long int | |
231 | time_wall_msec(void) | |
232 | { | |
75f9c912 | 233 | return time_msec__(&wall_clock); |
064af421 BP |
234 | } |
235 | ||
236 | /* Configures the program to die with SIGALRM 'secs' seconds from now, if | |
237 | * 'secs' is nonzero, or disables the feature if 'secs' is zero. */ | |
238 | void | |
239 | time_alarm(unsigned int secs) | |
240 | { | |
00a16895 EJ |
241 | long long int now; |
242 | long long int msecs; | |
243 | ||
728a8b14 | 244 | assert_single_threaded(); |
064af421 | 245 | time_init(); |
00a16895 EJ |
246 | |
247 | now = time_msec(); | |
75b0b752 | 248 | msecs = secs * 1000LL; |
00a16895 | 249 | deadline = now < LLONG_MAX - msecs ? now + msecs : LLONG_MAX; |
064af421 BP |
250 | } |
251 | ||
252 | /* Like poll(), except: | |
cee03df4 BP |
253 | * |
254 | * - The timeout is specified as an absolute time, as defined by | |
255 | * time_msec(), instead of a duration. | |
064af421 BP |
256 | * |
257 | * - On error, returns a negative error code (instead of setting errno). | |
258 | * | |
259 | * - If interrupted by a signal, retries automatically until the original | |
cee03df4 | 260 | * timeout is reached. (Because of this property, this function will |
064af421 BP |
261 | * never return -EINTR.) |
262 | * | |
cee03df4 | 263 | * Stores the number of milliseconds elapsed during poll in '*elapsed'. */ |
064af421 | 264 | int |
4ca828d7 LS |
265 | time_poll(struct pollfd *pollfds, int n_pollfds, HANDLE *handles OVS_UNUSED, |
266 | long long int timeout_when, int *elapsed) | |
064af421 | 267 | { |
4c694ff7 | 268 | long long int *last_wakeup = last_wakeup_get(); |
064af421 | 269 | long long int start; |
3308c696 | 270 | bool quiescent; |
4ca828d7 | 271 | int retval = 0; |
064af421 | 272 | |
4c694ff7 | 273 | time_init(); |
e2afa7cd BP |
274 | coverage_clear(); |
275 | coverage_run(); | |
2f8932e8 | 276 | if (*last_wakeup && !thread_is_pmd()) { |
4c694ff7 | 277 | log_poll_interval(*last_wakeup); |
d7a291ac | 278 | } |
064af421 | 279 | start = time_msec(); |
00a16895 EJ |
280 | |
281 | timeout_when = MIN(timeout_when, deadline); | |
3308c696 | 282 | quiescent = ovsrcu_is_quiescent(); |
00a16895 | 283 | |
064af421 | 284 | for (;;) { |
cee03df4 | 285 | long long int now = time_msec(); |
064af421 | 286 | int time_left; |
cee03df4 BP |
287 | |
288 | if (now >= timeout_when) { | |
289 | time_left = 0; | |
290 | } else if ((unsigned long long int) timeout_when - now > INT_MAX) { | |
291 | time_left = INT_MAX; | |
064af421 | 292 | } else { |
cee03df4 | 293 | time_left = timeout_when - now; |
064af421 BP |
294 | } |
295 | ||
3308c696 BP |
296 | if (!quiescent) { |
297 | if (!time_left) { | |
298 | ovsrcu_quiesce(); | |
299 | } else { | |
300 | ovsrcu_quiesce_start(); | |
301 | } | |
0f2ea848 BP |
302 | } |
303 | ||
4ca828d7 | 304 | #ifndef _WIN32 |
064af421 BP |
305 | retval = poll(pollfds, n_pollfds, time_left); |
306 | if (retval < 0) { | |
307 | retval = -errno; | |
308 | } | |
4ca828d7 LS |
309 | #else |
310 | if (n_pollfds > MAXIMUM_WAIT_OBJECTS) { | |
311 | VLOG_ERR("Cannot handle more than maximum wait objects\n"); | |
312 | } else if (n_pollfds != 0) { | |
313 | retval = WaitForMultipleObjects(n_pollfds, handles, FALSE, | |
314 | time_left); | |
315 | } | |
316 | if (retval < 0) { | |
317 | /* XXX This will be replace by a win error to errno | |
318 | conversion function */ | |
319 | retval = -WSAGetLastError(); | |
320 | retval = -EINVAL; | |
321 | } | |
322 | #endif | |
00a16895 | 323 | |
3308c696 | 324 | if (!quiescent && time_left) { |
0f2ea848 BP |
325 | ovsrcu_quiesce_end(); |
326 | } | |
327 | ||
00a16895 | 328 | if (deadline <= time_msec()) { |
84a6cbae | 329 | #ifndef _WIN32 |
00a16895 | 330 | fatal_signal_handler(SIGALRM); |
84a6cbae GS |
331 | #else |
332 | VLOG_ERR("wake up from WaitForMultipleObjects after deadline"); | |
333 | fatal_signal_handler(SIGTERM); | |
334 | #endif | |
00a16895 EJ |
335 | if (retval < 0) { |
336 | retval = 0; | |
337 | } | |
338 | break; | |
339 | } | |
340 | ||
064af421 BP |
341 | if (retval != -EINTR) { |
342 | break; | |
343 | } | |
064af421 | 344 | } |
4c694ff7 | 345 | *last_wakeup = time_msec(); |
959ec62e | 346 | refresh_rusage(); |
4c694ff7 | 347 | *elapsed = *last_wakeup - start; |
064af421 BP |
348 | return retval; |
349 | } | |
350 | ||
c73814a3 JG |
351 | long long int |
352 | timespec_to_msec(const struct timespec *ts) | |
353 | { | |
354 | return (long long int) ts->tv_sec * 1000 + ts->tv_nsec / (1000 * 1000); | |
355 | } | |
356 | ||
e7cfedd6 | 357 | long long int |
064af421 BP |
358 | timeval_to_msec(const struct timeval *tv) |
359 | { | |
360 | return (long long int) tv->tv_sec * 1000 + tv->tv_usec / 1000; | |
361 | } | |
362 | ||
4ae90ff9 | 363 | /* Returns the monotonic time at which the "time" module was initialized, in |
6f2302b0 | 364 | * milliseconds. */ |
4ae90ff9 BP |
365 | long long int |
366 | time_boot_msec(void) | |
367 | { | |
368 | time_init(); | |
369 | return boot_time; | |
370 | } | |
371 | ||
48f8613f GS |
372 | #ifdef _WIN32 |
373 | static ULARGE_INTEGER | |
374 | xgetfiletime(void) | |
375 | { | |
376 | ULARGE_INTEGER current_time; | |
377 | FILETIME current_time_ft; | |
378 | ||
379 | /* Returns current time in UTC as a 64-bit value representing the number | |
380 | * of 100-nanosecond intervals since January 1, 1601 . */ | |
381 | GetSystemTimePreciseAsFileTime(¤t_time_ft); | |
382 | current_time.LowPart = current_time_ft.dwLowDateTime; | |
383 | current_time.HighPart = current_time_ft.dwHighDateTime; | |
384 | ||
385 | return current_time; | |
386 | } | |
387 | ||
388 | static int | |
389 | clock_gettime(clock_t id, struct timespec *ts) | |
390 | { | |
391 | if (id == CLOCK_MONOTONIC) { | |
392 | static LARGE_INTEGER freq; | |
393 | LARGE_INTEGER count; | |
394 | long long int ns; | |
395 | ||
396 | if (!freq.QuadPart) { | |
397 | /* Number of counts per second. */ | |
398 | QueryPerformanceFrequency(&freq); | |
399 | } | |
400 | /* Total number of counts from a starting point. */ | |
401 | QueryPerformanceCounter(&count); | |
402 | ||
403 | /* Total nano seconds from a starting point. */ | |
404 | ns = (double) count.QuadPart / freq.QuadPart * 1000000000; | |
405 | ||
406 | ts->tv_sec = count.QuadPart / freq.QuadPart; | |
407 | ts->tv_nsec = ns % 1000000000; | |
408 | } else if (id == CLOCK_REALTIME) { | |
409 | ULARGE_INTEGER current_time = xgetfiletime(); | |
410 | ||
411 | /* Time from Epoch to now. */ | |
4537a423 GS |
412 | ts->tv_sec = (current_time.QuadPart - unix_epoch) / 10000000; |
413 | ts->tv_nsec = ((current_time.QuadPart - unix_epoch) % | |
48f8613f GS |
414 | 10000000) * 100; |
415 | } else { | |
416 | return -1; | |
417 | } | |
4537a423 GS |
418 | |
419 | return 0; | |
48f8613f GS |
420 | } |
421 | #endif /* _WIN32 */ | |
422 | ||
291716e1 LR |
423 | #ifdef __MACH__ |
424 | #include <mach/clock.h> | |
425 | #include <mach/mach.h> | |
426 | static int | |
427 | clock_gettime(clock_t id, struct timespec *ts) | |
428 | { | |
429 | mach_timespec_t mts; | |
430 | clock_serv_t clk; | |
431 | clock_id_t cid; | |
432 | ||
433 | if (id == CLOCK_MONOTONIC) { | |
434 | cid = SYSTEM_CLOCK; | |
435 | } else if (id == CLOCK_REALTIME) { | |
436 | cid = CALENDAR_CLOCK; | |
437 | } else { | |
438 | return -1; | |
439 | } | |
440 | ||
441 | host_get_clock_service(mach_host_self(), cid, &clk); | |
442 | clock_get_time(clk, &mts); | |
443 | mach_port_deallocate(mach_task_self(), clk); | |
444 | ts->tv_sec = mts.tv_sec; | |
445 | ts->tv_nsec = mts.tv_nsec; | |
446 | ||
447 | return 0; | |
448 | } | |
449 | #endif | |
450 | ||
279c9e03 BP |
451 | void |
452 | xgettimeofday(struct timeval *tv) | |
453 | { | |
bae94bc7 | 454 | #ifndef _WIN32 |
279c9e03 | 455 | if (gettimeofday(tv, NULL) == -1) { |
10a89ef0 | 456 | VLOG_FATAL("gettimeofday failed (%s)", ovs_strerror(errno)); |
279c9e03 | 457 | } |
bae94bc7 GS |
458 | #else |
459 | ULARGE_INTEGER current_time = xgetfiletime(); | |
460 | ||
4537a423 GS |
461 | tv->tv_sec = (current_time.QuadPart - unix_epoch) / 10000000; |
462 | tv->tv_usec = ((current_time.QuadPart - unix_epoch) % | |
bae94bc7 GS |
463 | 10000000) / 10; |
464 | #endif | |
279c9e03 BP |
465 | } |
466 | ||
bc7ad7d4 BP |
467 | void |
468 | xclock_gettime(clock_t id, struct timespec *ts) | |
469 | { | |
470 | if (clock_gettime(id, ts) == -1) { | |
471 | /* It seems like a bad idea to try to use vlog here because it is | |
472 | * likely to try to check the current time. */ | |
473 | ovs_abort(errno, "xclock_gettime() failed"); | |
474 | } | |
475 | } | |
476 | ||
8661af79 GS |
477 | static void |
478 | msec_to_timespec(long long int ms, struct timespec *ts) | |
479 | { | |
480 | ts->tv_sec = ms / 1000; | |
481 | ts->tv_nsec = (ms % 1000) * 1000 * 1000; | |
482 | } | |
483 | ||
484 | static void | |
485 | timewarp_work(void) | |
486 | { | |
487 | struct clock *c = &monotonic_clock; | |
488 | struct timespec warp; | |
489 | ||
490 | ovs_mutex_lock(&c->mutex); | |
491 | if (!c->large_warp.conn) { | |
492 | ovs_mutex_unlock(&c->mutex); | |
493 | return; | |
494 | } | |
495 | ||
496 | if (c->large_warp.total_warp >= c->large_warp.warp) { | |
497 | msec_to_timespec(c->large_warp.warp, &warp); | |
498 | timespec_add(&c->warp, &c->warp, &warp); | |
499 | c->large_warp.total_warp -= c->large_warp.warp; | |
500 | } else if (c->large_warp.total_warp) { | |
501 | msec_to_timespec(c->large_warp.total_warp, &warp); | |
502 | timespec_add(&c->warp, &c->warp, &warp); | |
503 | c->large_warp.total_warp = 0; | |
504 | } else { | |
505 | /* c->large_warp.total_warp is 0. */ | |
506 | msec_to_timespec(c->large_warp.warp, &warp); | |
507 | timespec_add(&c->warp, &c->warp, &warp); | |
508 | } | |
509 | ||
510 | if (!c->large_warp.total_warp) { | |
511 | unixctl_command_reply(c->large_warp.conn, "warped"); | |
512 | c->large_warp.conn = NULL; | |
513 | } | |
514 | ||
515 | ovs_mutex_unlock(&c->mutex); | |
516 | seq_change(timewarp_seq); | |
517 | ||
518 | /* give threads (eg. monitor) some chances to run */ | |
519 | #ifndef _WIN32 | |
520 | poll(NULL, 0, 10); | |
521 | #else | |
522 | Sleep(10); | |
523 | #endif | |
524 | } | |
525 | ||
526 | /* Perform work needed for "timewarp_seq"'s producer and consumers. */ | |
53d98a1e | 527 | void |
8661af79 | 528 | timewarp_run(void) |
53d98a1e | 529 | { |
8661af79 | 530 | /* The function is a no-op unless timeval_dummy_register() is called. */ |
53d98a1e | 531 | if (timewarp_enabled) { |
8661af79 GS |
532 | unsigned int thread_id; |
533 | ovs_mutex_lock(&monotonic_clock.mutex); | |
534 | thread_id = monotonic_clock.large_warp.main_thread_id; | |
535 | ovs_mutex_unlock(&monotonic_clock.mutex); | |
536 | ||
537 | if (thread_id != ovsthread_id_self()) { | |
538 | /* For threads other than the thread that changes the sequence, | |
539 | * wait on it. */ | |
540 | uint64_t *last_seq = last_seq_get(); | |
541 | ||
542 | *last_seq = seq_read(timewarp_seq); | |
543 | seq_wait(timewarp_seq, *last_seq); | |
544 | } else { | |
545 | /* Work on adding the remaining warps. */ | |
546 | timewarp_work(); | |
547 | } | |
53d98a1e AW |
548 | } |
549 | } | |
550 | ||
064af421 BP |
551 | static long long int |
552 | timeval_diff_msec(const struct timeval *a, const struct timeval *b) | |
553 | { | |
554 | return timeval_to_msec(a) - timeval_to_msec(b); | |
555 | } | |
556 | ||
6197af6e BP |
557 | static void |
558 | timespec_add(struct timespec *sum, | |
559 | const struct timespec *a, | |
560 | const struct timespec *b) | |
561 | { | |
562 | struct timespec tmp; | |
563 | ||
564 | tmp.tv_sec = a->tv_sec + b->tv_sec; | |
565 | tmp.tv_nsec = a->tv_nsec + b->tv_nsec; | |
566 | if (tmp.tv_nsec >= 1000 * 1000 * 1000) { | |
567 | tmp.tv_nsec -= 1000 * 1000 * 1000; | |
568 | tmp.tv_sec++; | |
569 | } | |
570 | ||
571 | *sum = tmp; | |
572 | } | |
573 | ||
3e509ec5 BP |
574 | static bool |
575 | is_warped(const struct clock *c) | |
576 | { | |
577 | bool warped; | |
578 | ||
e6249c68 | 579 | ovs_mutex_lock(&c->mutex); |
3e509ec5 | 580 | warped = monotonic_clock.warp.tv_sec || monotonic_clock.warp.tv_nsec; |
e6249c68 | 581 | ovs_mutex_unlock(&c->mutex); |
3e509ec5 BP |
582 | |
583 | return warped; | |
584 | } | |
585 | ||
064af421 | 586 | static void |
959ec62e | 587 | log_poll_interval(long long int last_wakeup) |
064af421 | 588 | { |
d7a291ac EJ |
589 | long long int interval = time_msec() - last_wakeup; |
590 | ||
3e509ec5 | 591 | if (interval >= 1000 && !is_warped(&monotonic_clock)) { |
d7a291ac EJ |
592 | const struct rusage *last_rusage = get_recent_rusage(); |
593 | struct rusage rusage; | |
594 | ||
653ce9d6 BP |
595 | if (!getrusage_thread(&rusage)) { |
596 | VLOG_WARN("Unreasonably long %lldms poll interval" | |
597 | " (%lldms user, %lldms system)", | |
598 | interval, | |
599 | timeval_diff_msec(&rusage.ru_utime, | |
600 | &last_rusage->ru_utime), | |
601 | timeval_diff_msec(&rusage.ru_stime, | |
602 | &last_rusage->ru_stime)); | |
603 | ||
604 | if (rusage.ru_minflt > last_rusage->ru_minflt | |
605 | || rusage.ru_majflt > last_rusage->ru_majflt) { | |
606 | VLOG_WARN("faults: %ld minor, %ld major", | |
607 | rusage.ru_minflt - last_rusage->ru_minflt, | |
608 | rusage.ru_majflt - last_rusage->ru_majflt); | |
609 | } | |
610 | if (rusage.ru_inblock > last_rusage->ru_inblock | |
611 | || rusage.ru_oublock > last_rusage->ru_oublock) { | |
612 | VLOG_WARN("disk: %ld reads, %ld writes", | |
613 | rusage.ru_inblock - last_rusage->ru_inblock, | |
614 | rusage.ru_oublock - last_rusage->ru_oublock); | |
615 | } | |
616 | if (rusage.ru_nvcsw > last_rusage->ru_nvcsw | |
617 | || rusage.ru_nivcsw > last_rusage->ru_nivcsw) { | |
618 | VLOG_WARN("context switches: %ld voluntary, %ld involuntary", | |
619 | rusage.ru_nvcsw - last_rusage->ru_nvcsw, | |
620 | rusage.ru_nivcsw - last_rusage->ru_nivcsw); | |
621 | } | |
622 | } else { | |
623 | VLOG_WARN("Unreasonably long %lldms poll interval", interval); | |
064af421 | 624 | } |
a5f607bc | 625 | coverage_log(); |
064af421 | 626 | } |
064af421 | 627 | } |
959ec62e BP |
628 | \f |
629 | /* CPU usage tracking. */ | |
630 | ||
631 | struct cpu_usage { | |
632 | long long int when; /* Time that this sample was taken. */ | |
633 | unsigned long long int cpu; /* Total user+system CPU usage when sampled. */ | |
634 | }; | |
635 | ||
4c694ff7 BP |
636 | struct cpu_tracker { |
637 | struct cpu_usage older; | |
638 | struct cpu_usage newer; | |
639 | int cpu_usage; | |
640 | ||
641 | struct rusage recent_rusage; | |
642 | }; | |
643 | DEFINE_PER_THREAD_MALLOCED_DATA(struct cpu_tracker *, cpu_tracker_var); | |
644 | ||
645 | static struct cpu_tracker * | |
646 | get_cpu_tracker(void) | |
647 | { | |
648 | struct cpu_tracker *t = cpu_tracker_var_get(); | |
649 | if (!t) { | |
650 | t = xzalloc(sizeof *t); | |
651 | t->older.when = LLONG_MIN; | |
652 | t->newer.when = LLONG_MIN; | |
653 | cpu_tracker_var_set_unsafe(t); | |
654 | } | |
655 | return t; | |
656 | } | |
959ec62e BP |
657 | |
658 | static struct rusage * | |
659 | get_recent_rusage(void) | |
660 | { | |
4c694ff7 BP |
661 | return &get_cpu_tracker()->recent_rusage; |
662 | } | |
663 | ||
664 | static int | |
665 | getrusage_thread(struct rusage *rusage OVS_UNUSED) | |
666 | { | |
667 | #ifdef RUSAGE_THREAD | |
668 | return getrusage(RUSAGE_THREAD, rusage); | |
669 | #else | |
670 | errno = EINVAL; | |
671 | return -1; | |
672 | #endif | |
959ec62e BP |
673 | } |
674 | ||
675 | static void | |
676 | refresh_rusage(void) | |
677 | { | |
4c694ff7 BP |
678 | struct cpu_tracker *t = get_cpu_tracker(); |
679 | struct rusage *recent_rusage = &t->recent_rusage; | |
959ec62e | 680 | |
4c694ff7 BP |
681 | if (!getrusage_thread(recent_rusage)) { |
682 | long long int now = time_msec(); | |
683 | if (now >= t->newer.when + 3 * 1000) { | |
684 | t->older = t->newer; | |
685 | t->newer.when = now; | |
686 | t->newer.cpu = (timeval_to_msec(&recent_rusage->ru_utime) + | |
687 | timeval_to_msec(&recent_rusage->ru_stime)); | |
688 | ||
689 | if (t->older.when != LLONG_MIN && t->newer.cpu > t->older.cpu) { | |
690 | unsigned int dividend = t->newer.cpu - t->older.cpu; | |
691 | unsigned int divisor = (t->newer.when - t->older.when) / 100; | |
692 | t->cpu_usage = divisor > 0 ? dividend / divisor : -1; | |
693 | } else { | |
694 | t->cpu_usage = -1; | |
695 | } | |
959ec62e BP |
696 | } |
697 | } | |
698 | } | |
699 | ||
700 | /* Returns an estimate of this process's CPU usage, as a percentage, over the | |
701 | * past few seconds of wall-clock time. Returns -1 if no estimate is available | |
702 | * (which will happen if the process has not been running long enough to have | |
703 | * an estimate, and can happen for other reasons as well). */ | |
704 | int | |
705 | get_cpu_usage(void) | |
706 | { | |
4c694ff7 | 707 | return get_cpu_tracker()->cpu_usage; |
959ec62e | 708 | } |
6197af6e BP |
709 | \f |
710 | /* Unixctl interface. */ | |
711 | ||
f802352d BP |
712 | /* "time/stop" stops the monotonic time returned by e.g. time_msec() from |
713 | * advancing, except due to later calls to "time/warp". */ | |
714 | static void | |
715 | timeval_stop_cb(struct unixctl_conn *conn, | |
716 | int argc OVS_UNUSED, const char *argv[] OVS_UNUSED, | |
717 | void *aux OVS_UNUSED) | |
718 | { | |
e6249c68 | 719 | ovs_mutex_lock(&monotonic_clock.mutex); |
fc4a1204 | 720 | atomic_store_relaxed(&monotonic_clock.slow_path, true); |
75f9c912 | 721 | monotonic_clock.stopped = true; |
31ef9f51 | 722 | xclock_gettime(monotonic_clock.id, &monotonic_clock.cache); |
e6249c68 | 723 | ovs_mutex_unlock(&monotonic_clock.mutex); |
75f9c912 | 724 | |
f802352d BP |
725 | unixctl_command_reply(conn, NULL); |
726 | } | |
727 | ||
728 | /* "time/warp MSECS" advances the current monotonic time by the specified | |
729 | * number of milliseconds. Unless "time/stop" has also been executed, the | |
730 | * monotonic clock continues to tick forward at the normal rate afterward. | |
731 | * | |
8661af79 GS |
732 | * "time/warp LARGE_MSECS MSECS" is a variation of the above command. It |
733 | * advances the current monotonic time by LARGE_MSECS. This is done MSECS | |
734 | * at a time in each run of the main thread. This gives other threads | |
735 | * time to run after the clock has been advanced by MSECS. | |
736 | * | |
f802352d | 737 | * Does not affect wall clock readings. */ |
6197af6e BP |
738 | static void |
739 | timeval_warp_cb(struct unixctl_conn *conn, | |
740 | int argc OVS_UNUSED, const char *argv[], void *aux OVS_UNUSED) | |
741 | { | |
8661af79 GS |
742 | long long int total_warp = argc > 2 ? atoll(argv[1]) : 0; |
743 | long long int msecs = argc > 2 ? atoll(argv[2]) : atoll(argv[1]); | |
744 | if (msecs <= 0 || total_warp < 0) { | |
bde9f75d | 745 | unixctl_command_reply_error(conn, "invalid MSECS"); |
6197af6e BP |
746 | return; |
747 | } | |
748 | ||
e6249c68 | 749 | ovs_mutex_lock(&monotonic_clock.mutex); |
8661af79 GS |
750 | if (monotonic_clock.large_warp.conn) { |
751 | ovs_mutex_unlock(&monotonic_clock.mutex); | |
752 | unixctl_command_reply_error(conn, "A previous warp in progress"); | |
753 | return; | |
754 | } | |
fc4a1204 | 755 | atomic_store_relaxed(&monotonic_clock.slow_path, true); |
8661af79 GS |
756 | monotonic_clock.large_warp.conn = conn; |
757 | monotonic_clock.large_warp.total_warp = total_warp; | |
758 | monotonic_clock.large_warp.warp = msecs; | |
759 | monotonic_clock.large_warp.main_thread_id = ovsthread_id_self(); | |
e6249c68 | 760 | ovs_mutex_unlock(&monotonic_clock.mutex); |
8661af79 GS |
761 | |
762 | timewarp_work(); | |
6197af6e BP |
763 | } |
764 | ||
765 | void | |
766 | timeval_dummy_register(void) | |
767 | { | |
53d98a1e | 768 | timewarp_enabled = true; |
f802352d | 769 | unixctl_command_register("time/stop", "", 0, 0, timeval_stop_cb, NULL); |
74467d5c | 770 | unixctl_command_register("time/warp", "[large_msecs] msecs", 1, 2, |
6197af6e BP |
771 | timeval_warp_cb, NULL); |
772 | } | |
2b31d8e7 PI |
773 | |
774 | ||
775 | ||
776 | /* strftime() with an extension for high-resolution timestamps. Any '#'s in | |
777 | * 'format' will be replaced by subseconds, e.g. use "%S.###" to obtain results | |
778 | * like "01.123". */ | |
779 | size_t | |
780 | strftime_msec(char *s, size_t max, const char *format, | |
781 | const struct tm_msec *tm) | |
782 | { | |
783 | size_t n; | |
784 | ||
2b89438d GS |
785 | /* Visual Studio 2013's behavior is to crash when 0 is passed as second |
786 | * argument to strftime. */ | |
787 | n = max ? strftime(s, max, format, &tm->tm) : 0; | |
2b31d8e7 PI |
788 | if (n) { |
789 | char decimals[4]; | |
790 | char *p; | |
791 | ||
792 | sprintf(decimals, "%03d", tm->msec); | |
793 | for (p = strchr(s, '#'); p; p = strchr(p, '#')) { | |
794 | char *d = decimals; | |
795 | while (*p == '#') { | |
796 | *p++ = *d ? *d++ : '0'; | |
797 | } | |
798 | } | |
799 | } | |
800 | ||
801 | return n; | |
802 | } | |
803 | ||
804 | struct tm_msec * | |
805 | localtime_msec(long long int now, struct tm_msec *result) | |
806 | { | |
807 | time_t now_sec = now / 1000; | |
808 | localtime_r(&now_sec, &result->tm); | |
809 | result->msec = now % 1000; | |
810 | return result; | |
811 | } | |
812 | ||
813 | struct tm_msec * | |
814 | gmtime_msec(long long int now, struct tm_msec *result) | |
815 | { | |
816 | time_t now_sec = now / 1000; | |
817 | gmtime_r(&now_sec, &result->tm); | |
818 | result->msec = now % 1000; | |
819 | return result; | |
820 | } |