]>
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 | |
10fd9f6e | 44 | #if !defined(HAVE_CLOCK_GETTIME) |
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 | |
10fd9f6e | 55 | #endif /* !defined(HAVE_CLOCK_GETTIME) */ |
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 | ||
89bbc6a9 | 174 | /* Stores a monotonic timer into '*ts'. */ |
064af421 | 175 | void |
75f9c912 | 176 | time_timespec(struct timespec *ts) |
064af421 | 177 | { |
75f9c912 BP |
178 | time_timespec__(&monotonic_clock, ts); |
179 | } | |
180 | ||
89bbc6a9 | 181 | /* Stores the current time into '*ts'. */ |
75f9c912 BP |
182 | void |
183 | time_wall_timespec(struct timespec *ts) | |
184 | { | |
185 | time_timespec__(&wall_clock, ts); | |
186 | } | |
187 | ||
188 | static time_t | |
189 | time_sec__(struct clock *c) | |
190 | { | |
191 | struct timespec ts; | |
192 | ||
193 | time_timespec__(c, &ts); | |
194 | return ts.tv_sec; | |
064af421 BP |
195 | } |
196 | ||
c73814a3 | 197 | /* Returns a monotonic timer, in seconds. */ |
064af421 BP |
198 | time_t |
199 | time_now(void) | |
200 | { | |
75f9c912 | 201 | return time_sec__(&monotonic_clock); |
064af421 BP |
202 | } |
203 | ||
c73814a3 JG |
204 | /* Returns the current time, in seconds. */ |
205 | time_t | |
206 | time_wall(void) | |
207 | { | |
75f9c912 BP |
208 | return time_sec__(&wall_clock); |
209 | } | |
210 | ||
211 | static long long int | |
212 | time_msec__(struct clock *c) | |
213 | { | |
214 | struct timespec ts; | |
215 | ||
216 | time_timespec__(c, &ts); | |
217 | return timespec_to_msec(&ts); | |
c73814a3 JG |
218 | } |
219 | ||
89bbc6a9 | 220 | /* Returns a monotonic timer, in ms. */ |
064af421 BP |
221 | long long int |
222 | time_msec(void) | |
223 | { | |
75f9c912 | 224 | return time_msec__(&monotonic_clock); |
c73814a3 JG |
225 | } |
226 | ||
89bbc6a9 | 227 | /* Returns the current time, in ms. */ |
c73814a3 JG |
228 | long long int |
229 | time_wall_msec(void) | |
230 | { | |
75f9c912 | 231 | return time_msec__(&wall_clock); |
064af421 BP |
232 | } |
233 | ||
bf168c45 IM |
234 | static long long int |
235 | time_usec__(struct clock *c) | |
236 | { | |
237 | struct timespec ts; | |
238 | ||
239 | time_timespec__(c, &ts); | |
240 | return timespec_to_usec(&ts); | |
241 | } | |
242 | ||
243 | /* Returns a monotonic timer, in microseconds. */ | |
244 | long long int | |
245 | time_usec(void) | |
246 | { | |
247 | return time_usec__(&monotonic_clock); | |
248 | } | |
249 | ||
250 | /* Returns the current time, in microseconds. */ | |
251 | long long int | |
252 | time_wall_usec(void) | |
253 | { | |
254 | return time_usec__(&wall_clock); | |
255 | } | |
256 | ||
064af421 BP |
257 | /* Configures the program to die with SIGALRM 'secs' seconds from now, if |
258 | * 'secs' is nonzero, or disables the feature if 'secs' is zero. */ | |
259 | void | |
260 | time_alarm(unsigned int secs) | |
261 | { | |
00a16895 EJ |
262 | long long int now; |
263 | long long int msecs; | |
264 | ||
728a8b14 | 265 | assert_single_threaded(); |
064af421 | 266 | time_init(); |
00a16895 EJ |
267 | |
268 | now = time_msec(); | |
75b0b752 | 269 | msecs = secs * 1000LL; |
00a16895 | 270 | deadline = now < LLONG_MAX - msecs ? now + msecs : LLONG_MAX; |
064af421 BP |
271 | } |
272 | ||
273 | /* Like poll(), except: | |
cee03df4 BP |
274 | * |
275 | * - The timeout is specified as an absolute time, as defined by | |
276 | * time_msec(), instead of a duration. | |
064af421 BP |
277 | * |
278 | * - On error, returns a negative error code (instead of setting errno). | |
279 | * | |
280 | * - If interrupted by a signal, retries automatically until the original | |
cee03df4 | 281 | * timeout is reached. (Because of this property, this function will |
064af421 BP |
282 | * never return -EINTR.) |
283 | * | |
cee03df4 | 284 | * Stores the number of milliseconds elapsed during poll in '*elapsed'. */ |
064af421 | 285 | int |
4ca828d7 LS |
286 | time_poll(struct pollfd *pollfds, int n_pollfds, HANDLE *handles OVS_UNUSED, |
287 | long long int timeout_when, int *elapsed) | |
064af421 | 288 | { |
4c694ff7 | 289 | long long int *last_wakeup = last_wakeup_get(); |
064af421 | 290 | long long int start; |
3308c696 | 291 | bool quiescent; |
4ca828d7 | 292 | int retval = 0; |
064af421 | 293 | |
4c694ff7 | 294 | time_init(); |
e2afa7cd BP |
295 | coverage_clear(); |
296 | coverage_run(); | |
2f8932e8 | 297 | if (*last_wakeup && !thread_is_pmd()) { |
4c694ff7 | 298 | log_poll_interval(*last_wakeup); |
d7a291ac | 299 | } |
064af421 | 300 | start = time_msec(); |
00a16895 EJ |
301 | |
302 | timeout_when = MIN(timeout_when, deadline); | |
3308c696 | 303 | quiescent = ovsrcu_is_quiescent(); |
00a16895 | 304 | |
064af421 | 305 | for (;;) { |
cee03df4 | 306 | long long int now = time_msec(); |
064af421 | 307 | int time_left; |
cee03df4 BP |
308 | |
309 | if (now >= timeout_when) { | |
310 | time_left = 0; | |
311 | } else if ((unsigned long long int) timeout_when - now > INT_MAX) { | |
312 | time_left = INT_MAX; | |
064af421 | 313 | } else { |
cee03df4 | 314 | time_left = timeout_when - now; |
064af421 BP |
315 | } |
316 | ||
3308c696 BP |
317 | if (!quiescent) { |
318 | if (!time_left) { | |
319 | ovsrcu_quiesce(); | |
320 | } else { | |
321 | ovsrcu_quiesce_start(); | |
322 | } | |
0f2ea848 BP |
323 | } |
324 | ||
4ca828d7 | 325 | #ifndef _WIN32 |
064af421 BP |
326 | retval = poll(pollfds, n_pollfds, time_left); |
327 | if (retval < 0) { | |
328 | retval = -errno; | |
329 | } | |
4ca828d7 LS |
330 | #else |
331 | if (n_pollfds > MAXIMUM_WAIT_OBJECTS) { | |
332 | VLOG_ERR("Cannot handle more than maximum wait objects\n"); | |
333 | } else if (n_pollfds != 0) { | |
334 | retval = WaitForMultipleObjects(n_pollfds, handles, FALSE, | |
335 | time_left); | |
336 | } | |
337 | if (retval < 0) { | |
338 | /* XXX This will be replace by a win error to errno | |
339 | conversion function */ | |
340 | retval = -WSAGetLastError(); | |
341 | retval = -EINVAL; | |
342 | } | |
343 | #endif | |
00a16895 | 344 | |
3308c696 | 345 | if (!quiescent && time_left) { |
0f2ea848 BP |
346 | ovsrcu_quiesce_end(); |
347 | } | |
348 | ||
00a16895 | 349 | if (deadline <= time_msec()) { |
84a6cbae | 350 | #ifndef _WIN32 |
00a16895 | 351 | fatal_signal_handler(SIGALRM); |
84a6cbae GS |
352 | #else |
353 | VLOG_ERR("wake up from WaitForMultipleObjects after deadline"); | |
354 | fatal_signal_handler(SIGTERM); | |
355 | #endif | |
00a16895 EJ |
356 | if (retval < 0) { |
357 | retval = 0; | |
358 | } | |
359 | break; | |
360 | } | |
361 | ||
064af421 BP |
362 | if (retval != -EINTR) { |
363 | break; | |
364 | } | |
064af421 | 365 | } |
4c694ff7 | 366 | *last_wakeup = time_msec(); |
959ec62e | 367 | refresh_rusage(); |
4c694ff7 | 368 | *elapsed = *last_wakeup - start; |
064af421 BP |
369 | return retval; |
370 | } | |
371 | ||
c73814a3 JG |
372 | long long int |
373 | timespec_to_msec(const struct timespec *ts) | |
374 | { | |
375 | return (long long int) ts->tv_sec * 1000 + ts->tv_nsec / (1000 * 1000); | |
376 | } | |
377 | ||
e7cfedd6 | 378 | long long int |
064af421 BP |
379 | timeval_to_msec(const struct timeval *tv) |
380 | { | |
381 | return (long long int) tv->tv_sec * 1000 + tv->tv_usec / 1000; | |
382 | } | |
383 | ||
bf168c45 IM |
384 | long long int |
385 | timespec_to_usec(const struct timespec *ts) | |
386 | { | |
387 | return (long long int) ts->tv_sec * 1000 * 1000 + ts->tv_nsec / 1000; | |
388 | } | |
389 | ||
390 | long long int | |
391 | timeval_to_usec(const struct timeval *tv) | |
392 | { | |
393 | return (long long int) tv->tv_sec * 1000 * 1000 + tv->tv_usec; | |
394 | } | |
395 | ||
4ae90ff9 | 396 | /* Returns the monotonic time at which the "time" module was initialized, in |
6f2302b0 | 397 | * milliseconds. */ |
4ae90ff9 BP |
398 | long long int |
399 | time_boot_msec(void) | |
400 | { | |
401 | time_init(); | |
402 | return boot_time; | |
403 | } | |
404 | ||
48f8613f GS |
405 | #ifdef _WIN32 |
406 | static ULARGE_INTEGER | |
407 | xgetfiletime(void) | |
408 | { | |
409 | ULARGE_INTEGER current_time; | |
410 | FILETIME current_time_ft; | |
411 | ||
412 | /* Returns current time in UTC as a 64-bit value representing the number | |
413 | * of 100-nanosecond intervals since January 1, 1601 . */ | |
414 | GetSystemTimePreciseAsFileTime(¤t_time_ft); | |
415 | current_time.LowPart = current_time_ft.dwLowDateTime; | |
416 | current_time.HighPart = current_time_ft.dwHighDateTime; | |
417 | ||
418 | return current_time; | |
419 | } | |
420 | ||
421 | static int | |
422 | clock_gettime(clock_t id, struct timespec *ts) | |
423 | { | |
424 | if (id == CLOCK_MONOTONIC) { | |
425 | static LARGE_INTEGER freq; | |
426 | LARGE_INTEGER count; | |
427 | long long int ns; | |
428 | ||
429 | if (!freq.QuadPart) { | |
430 | /* Number of counts per second. */ | |
431 | QueryPerformanceFrequency(&freq); | |
432 | } | |
433 | /* Total number of counts from a starting point. */ | |
434 | QueryPerformanceCounter(&count); | |
435 | ||
436 | /* Total nano seconds from a starting point. */ | |
437 | ns = (double) count.QuadPart / freq.QuadPart * 1000000000; | |
438 | ||
439 | ts->tv_sec = count.QuadPart / freq.QuadPart; | |
440 | ts->tv_nsec = ns % 1000000000; | |
441 | } else if (id == CLOCK_REALTIME) { | |
442 | ULARGE_INTEGER current_time = xgetfiletime(); | |
443 | ||
444 | /* Time from Epoch to now. */ | |
4537a423 GS |
445 | ts->tv_sec = (current_time.QuadPart - unix_epoch) / 10000000; |
446 | ts->tv_nsec = ((current_time.QuadPart - unix_epoch) % | |
48f8613f GS |
447 | 10000000) * 100; |
448 | } else { | |
449 | return -1; | |
450 | } | |
4537a423 GS |
451 | |
452 | return 0; | |
48f8613f GS |
453 | } |
454 | #endif /* _WIN32 */ | |
455 | ||
10fd9f6e | 456 | #if defined(__MACH__) && !defined(HAVE_CLOCK_GETTIME) |
291716e1 LR |
457 | #include <mach/clock.h> |
458 | #include <mach/mach.h> | |
459 | static int | |
460 | clock_gettime(clock_t id, struct timespec *ts) | |
461 | { | |
462 | mach_timespec_t mts; | |
463 | clock_serv_t clk; | |
464 | clock_id_t cid; | |
465 | ||
466 | if (id == CLOCK_MONOTONIC) { | |
467 | cid = SYSTEM_CLOCK; | |
468 | } else if (id == CLOCK_REALTIME) { | |
469 | cid = CALENDAR_CLOCK; | |
470 | } else { | |
471 | return -1; | |
472 | } | |
473 | ||
474 | host_get_clock_service(mach_host_self(), cid, &clk); | |
475 | clock_get_time(clk, &mts); | |
476 | mach_port_deallocate(mach_task_self(), clk); | |
477 | ts->tv_sec = mts.tv_sec; | |
478 | ts->tv_nsec = mts.tv_nsec; | |
479 | ||
480 | return 0; | |
481 | } | |
482 | #endif | |
483 | ||
279c9e03 BP |
484 | void |
485 | xgettimeofday(struct timeval *tv) | |
486 | { | |
bae94bc7 | 487 | #ifndef _WIN32 |
279c9e03 | 488 | if (gettimeofday(tv, NULL) == -1) { |
10a89ef0 | 489 | VLOG_FATAL("gettimeofday failed (%s)", ovs_strerror(errno)); |
279c9e03 | 490 | } |
bae94bc7 GS |
491 | #else |
492 | ULARGE_INTEGER current_time = xgetfiletime(); | |
493 | ||
4537a423 GS |
494 | tv->tv_sec = (current_time.QuadPart - unix_epoch) / 10000000; |
495 | tv->tv_usec = ((current_time.QuadPart - unix_epoch) % | |
bae94bc7 GS |
496 | 10000000) / 10; |
497 | #endif | |
279c9e03 BP |
498 | } |
499 | ||
bc7ad7d4 BP |
500 | void |
501 | xclock_gettime(clock_t id, struct timespec *ts) | |
502 | { | |
503 | if (clock_gettime(id, ts) == -1) { | |
504 | /* It seems like a bad idea to try to use vlog here because it is | |
505 | * likely to try to check the current time. */ | |
506 | ovs_abort(errno, "xclock_gettime() failed"); | |
507 | } | |
508 | } | |
509 | ||
8661af79 GS |
510 | static void |
511 | msec_to_timespec(long long int ms, struct timespec *ts) | |
512 | { | |
513 | ts->tv_sec = ms / 1000; | |
514 | ts->tv_nsec = (ms % 1000) * 1000 * 1000; | |
515 | } | |
516 | ||
ca3cc1aa BB |
517 | void |
518 | nsec_to_timespec(long long int nsec, struct timespec *ts) | |
519 | { | |
520 | if (!nsec) { | |
521 | ts->tv_sec = ts->tv_nsec = 0; | |
522 | return; | |
523 | } | |
524 | ts->tv_sec = nsec / (1000 * 1000 * 1000); | |
525 | ||
526 | nsec = nsec % (1000 * 1000 * 1000); | |
527 | /* This is to handle dates before epoch. */ | |
528 | if (OVS_UNLIKELY(nsec < 0)) { | |
529 | nsec += 1000 * 1000 * 1000; | |
530 | ts->tv_sec--; | |
531 | } | |
532 | ||
533 | ts->tv_nsec = nsec; | |
534 | } | |
535 | ||
8661af79 GS |
536 | static void |
537 | timewarp_work(void) | |
538 | { | |
539 | struct clock *c = &monotonic_clock; | |
540 | struct timespec warp; | |
541 | ||
542 | ovs_mutex_lock(&c->mutex); | |
543 | if (!c->large_warp.conn) { | |
544 | ovs_mutex_unlock(&c->mutex); | |
545 | return; | |
546 | } | |
547 | ||
548 | if (c->large_warp.total_warp >= c->large_warp.warp) { | |
549 | msec_to_timespec(c->large_warp.warp, &warp); | |
550 | timespec_add(&c->warp, &c->warp, &warp); | |
551 | c->large_warp.total_warp -= c->large_warp.warp; | |
552 | } else if (c->large_warp.total_warp) { | |
553 | msec_to_timespec(c->large_warp.total_warp, &warp); | |
554 | timespec_add(&c->warp, &c->warp, &warp); | |
555 | c->large_warp.total_warp = 0; | |
556 | } else { | |
557 | /* c->large_warp.total_warp is 0. */ | |
558 | msec_to_timespec(c->large_warp.warp, &warp); | |
559 | timespec_add(&c->warp, &c->warp, &warp); | |
560 | } | |
561 | ||
562 | if (!c->large_warp.total_warp) { | |
563 | unixctl_command_reply(c->large_warp.conn, "warped"); | |
564 | c->large_warp.conn = NULL; | |
565 | } | |
566 | ||
567 | ovs_mutex_unlock(&c->mutex); | |
568 | seq_change(timewarp_seq); | |
569 | ||
570 | /* give threads (eg. monitor) some chances to run */ | |
571 | #ifndef _WIN32 | |
572 | poll(NULL, 0, 10); | |
573 | #else | |
574 | Sleep(10); | |
575 | #endif | |
576 | } | |
577 | ||
578 | /* Perform work needed for "timewarp_seq"'s producer and consumers. */ | |
53d98a1e | 579 | void |
8661af79 | 580 | timewarp_run(void) |
53d98a1e | 581 | { |
8661af79 | 582 | /* The function is a no-op unless timeval_dummy_register() is called. */ |
53d98a1e | 583 | if (timewarp_enabled) { |
8661af79 GS |
584 | unsigned int thread_id; |
585 | ovs_mutex_lock(&monotonic_clock.mutex); | |
586 | thread_id = monotonic_clock.large_warp.main_thread_id; | |
587 | ovs_mutex_unlock(&monotonic_clock.mutex); | |
588 | ||
589 | if (thread_id != ovsthread_id_self()) { | |
590 | /* For threads other than the thread that changes the sequence, | |
591 | * wait on it. */ | |
592 | uint64_t *last_seq = last_seq_get(); | |
593 | ||
594 | *last_seq = seq_read(timewarp_seq); | |
595 | seq_wait(timewarp_seq, *last_seq); | |
596 | } else { | |
597 | /* Work on adding the remaining warps. */ | |
598 | timewarp_work(); | |
599 | } | |
53d98a1e AW |
600 | } |
601 | } | |
602 | ||
064af421 BP |
603 | static long long int |
604 | timeval_diff_msec(const struct timeval *a, const struct timeval *b) | |
605 | { | |
606 | return timeval_to_msec(a) - timeval_to_msec(b); | |
607 | } | |
608 | ||
6197af6e BP |
609 | static void |
610 | timespec_add(struct timespec *sum, | |
611 | const struct timespec *a, | |
612 | const struct timespec *b) | |
613 | { | |
614 | struct timespec tmp; | |
615 | ||
616 | tmp.tv_sec = a->tv_sec + b->tv_sec; | |
617 | tmp.tv_nsec = a->tv_nsec + b->tv_nsec; | |
618 | if (tmp.tv_nsec >= 1000 * 1000 * 1000) { | |
619 | tmp.tv_nsec -= 1000 * 1000 * 1000; | |
620 | tmp.tv_sec++; | |
621 | } | |
622 | ||
623 | *sum = tmp; | |
624 | } | |
625 | ||
3e509ec5 BP |
626 | static bool |
627 | is_warped(const struct clock *c) | |
628 | { | |
629 | bool warped; | |
630 | ||
e6249c68 | 631 | ovs_mutex_lock(&c->mutex); |
3e509ec5 | 632 | warped = monotonic_clock.warp.tv_sec || monotonic_clock.warp.tv_nsec; |
e6249c68 | 633 | ovs_mutex_unlock(&c->mutex); |
3e509ec5 BP |
634 | |
635 | return warped; | |
636 | } | |
637 | ||
064af421 | 638 | static void |
959ec62e | 639 | log_poll_interval(long long int last_wakeup) |
064af421 | 640 | { |
d7a291ac EJ |
641 | long long int interval = time_msec() - last_wakeup; |
642 | ||
3e509ec5 | 643 | if (interval >= 1000 && !is_warped(&monotonic_clock)) { |
d7a291ac EJ |
644 | const struct rusage *last_rusage = get_recent_rusage(); |
645 | struct rusage rusage; | |
646 | ||
653ce9d6 BP |
647 | if (!getrusage_thread(&rusage)) { |
648 | VLOG_WARN("Unreasonably long %lldms poll interval" | |
649 | " (%lldms user, %lldms system)", | |
650 | interval, | |
651 | timeval_diff_msec(&rusage.ru_utime, | |
652 | &last_rusage->ru_utime), | |
653 | timeval_diff_msec(&rusage.ru_stime, | |
654 | &last_rusage->ru_stime)); | |
655 | ||
656 | if (rusage.ru_minflt > last_rusage->ru_minflt | |
657 | || rusage.ru_majflt > last_rusage->ru_majflt) { | |
658 | VLOG_WARN("faults: %ld minor, %ld major", | |
659 | rusage.ru_minflt - last_rusage->ru_minflt, | |
660 | rusage.ru_majflt - last_rusage->ru_majflt); | |
661 | } | |
662 | if (rusage.ru_inblock > last_rusage->ru_inblock | |
663 | || rusage.ru_oublock > last_rusage->ru_oublock) { | |
664 | VLOG_WARN("disk: %ld reads, %ld writes", | |
665 | rusage.ru_inblock - last_rusage->ru_inblock, | |
666 | rusage.ru_oublock - last_rusage->ru_oublock); | |
667 | } | |
668 | if (rusage.ru_nvcsw > last_rusage->ru_nvcsw | |
669 | || rusage.ru_nivcsw > last_rusage->ru_nivcsw) { | |
670 | VLOG_WARN("context switches: %ld voluntary, %ld involuntary", | |
671 | rusage.ru_nvcsw - last_rusage->ru_nvcsw, | |
672 | rusage.ru_nivcsw - last_rusage->ru_nivcsw); | |
673 | } | |
674 | } else { | |
675 | VLOG_WARN("Unreasonably long %lldms poll interval", interval); | |
064af421 | 676 | } |
a5f607bc | 677 | coverage_log(); |
064af421 | 678 | } |
064af421 | 679 | } |
959ec62e BP |
680 | \f |
681 | /* CPU usage tracking. */ | |
682 | ||
683 | struct cpu_usage { | |
684 | long long int when; /* Time that this sample was taken. */ | |
685 | unsigned long long int cpu; /* Total user+system CPU usage when sampled. */ | |
686 | }; | |
687 | ||
4c694ff7 BP |
688 | struct cpu_tracker { |
689 | struct cpu_usage older; | |
690 | struct cpu_usage newer; | |
691 | int cpu_usage; | |
692 | ||
693 | struct rusage recent_rusage; | |
694 | }; | |
695 | DEFINE_PER_THREAD_MALLOCED_DATA(struct cpu_tracker *, cpu_tracker_var); | |
696 | ||
697 | static struct cpu_tracker * | |
698 | get_cpu_tracker(void) | |
699 | { | |
700 | struct cpu_tracker *t = cpu_tracker_var_get(); | |
701 | if (!t) { | |
702 | t = xzalloc(sizeof *t); | |
703 | t->older.when = LLONG_MIN; | |
704 | t->newer.when = LLONG_MIN; | |
705 | cpu_tracker_var_set_unsafe(t); | |
706 | } | |
707 | return t; | |
708 | } | |
959ec62e BP |
709 | |
710 | static struct rusage * | |
711 | get_recent_rusage(void) | |
712 | { | |
4c694ff7 BP |
713 | return &get_cpu_tracker()->recent_rusage; |
714 | } | |
715 | ||
716 | static int | |
717 | getrusage_thread(struct rusage *rusage OVS_UNUSED) | |
718 | { | |
719 | #ifdef RUSAGE_THREAD | |
720 | return getrusage(RUSAGE_THREAD, rusage); | |
721 | #else | |
722 | errno = EINVAL; | |
723 | return -1; | |
724 | #endif | |
959ec62e BP |
725 | } |
726 | ||
727 | static void | |
728 | refresh_rusage(void) | |
729 | { | |
4c694ff7 BP |
730 | struct cpu_tracker *t = get_cpu_tracker(); |
731 | struct rusage *recent_rusage = &t->recent_rusage; | |
959ec62e | 732 | |
4c694ff7 BP |
733 | if (!getrusage_thread(recent_rusage)) { |
734 | long long int now = time_msec(); | |
735 | if (now >= t->newer.when + 3 * 1000) { | |
736 | t->older = t->newer; | |
737 | t->newer.when = now; | |
738 | t->newer.cpu = (timeval_to_msec(&recent_rusage->ru_utime) + | |
739 | timeval_to_msec(&recent_rusage->ru_stime)); | |
740 | ||
741 | if (t->older.when != LLONG_MIN && t->newer.cpu > t->older.cpu) { | |
742 | unsigned int dividend = t->newer.cpu - t->older.cpu; | |
743 | unsigned int divisor = (t->newer.when - t->older.when) / 100; | |
744 | t->cpu_usage = divisor > 0 ? dividend / divisor : -1; | |
745 | } else { | |
746 | t->cpu_usage = -1; | |
747 | } | |
959ec62e BP |
748 | } |
749 | } | |
750 | } | |
751 | ||
752 | /* Returns an estimate of this process's CPU usage, as a percentage, over the | |
753 | * past few seconds of wall-clock time. Returns -1 if no estimate is available | |
754 | * (which will happen if the process has not been running long enough to have | |
755 | * an estimate, and can happen for other reasons as well). */ | |
756 | int | |
757 | get_cpu_usage(void) | |
758 | { | |
4c694ff7 | 759 | return get_cpu_tracker()->cpu_usage; |
959ec62e | 760 | } |
6197af6e BP |
761 | \f |
762 | /* Unixctl interface. */ | |
763 | ||
f802352d BP |
764 | /* "time/stop" stops the monotonic time returned by e.g. time_msec() from |
765 | * advancing, except due to later calls to "time/warp". */ | |
766 | static void | |
767 | timeval_stop_cb(struct unixctl_conn *conn, | |
768 | int argc OVS_UNUSED, const char *argv[] OVS_UNUSED, | |
769 | void *aux OVS_UNUSED) | |
770 | { | |
e6249c68 | 771 | ovs_mutex_lock(&monotonic_clock.mutex); |
fc4a1204 | 772 | atomic_store_relaxed(&monotonic_clock.slow_path, true); |
75f9c912 | 773 | monotonic_clock.stopped = true; |
31ef9f51 | 774 | xclock_gettime(monotonic_clock.id, &monotonic_clock.cache); |
e6249c68 | 775 | ovs_mutex_unlock(&monotonic_clock.mutex); |
75f9c912 | 776 | |
f802352d BP |
777 | unixctl_command_reply(conn, NULL); |
778 | } | |
779 | ||
780 | /* "time/warp MSECS" advances the current monotonic time by the specified | |
781 | * number of milliseconds. Unless "time/stop" has also been executed, the | |
782 | * monotonic clock continues to tick forward at the normal rate afterward. | |
783 | * | |
8661af79 GS |
784 | * "time/warp LARGE_MSECS MSECS" is a variation of the above command. It |
785 | * advances the current monotonic time by LARGE_MSECS. This is done MSECS | |
786 | * at a time in each run of the main thread. This gives other threads | |
787 | * time to run after the clock has been advanced by MSECS. | |
788 | * | |
f802352d | 789 | * Does not affect wall clock readings. */ |
6197af6e BP |
790 | static void |
791 | timeval_warp_cb(struct unixctl_conn *conn, | |
792 | int argc OVS_UNUSED, const char *argv[], void *aux OVS_UNUSED) | |
793 | { | |
8661af79 GS |
794 | long long int total_warp = argc > 2 ? atoll(argv[1]) : 0; |
795 | long long int msecs = argc > 2 ? atoll(argv[2]) : atoll(argv[1]); | |
796 | if (msecs <= 0 || total_warp < 0) { | |
bde9f75d | 797 | unixctl_command_reply_error(conn, "invalid MSECS"); |
6197af6e BP |
798 | return; |
799 | } | |
800 | ||
e6249c68 | 801 | ovs_mutex_lock(&monotonic_clock.mutex); |
8661af79 GS |
802 | if (monotonic_clock.large_warp.conn) { |
803 | ovs_mutex_unlock(&monotonic_clock.mutex); | |
804 | unixctl_command_reply_error(conn, "A previous warp in progress"); | |
805 | return; | |
806 | } | |
fc4a1204 | 807 | atomic_store_relaxed(&monotonic_clock.slow_path, true); |
8661af79 GS |
808 | monotonic_clock.large_warp.conn = conn; |
809 | monotonic_clock.large_warp.total_warp = total_warp; | |
810 | monotonic_clock.large_warp.warp = msecs; | |
811 | monotonic_clock.large_warp.main_thread_id = ovsthread_id_self(); | |
e6249c68 | 812 | ovs_mutex_unlock(&monotonic_clock.mutex); |
8661af79 GS |
813 | |
814 | timewarp_work(); | |
6197af6e BP |
815 | } |
816 | ||
817 | void | |
818 | timeval_dummy_register(void) | |
819 | { | |
53d98a1e | 820 | timewarp_enabled = true; |
f802352d | 821 | unixctl_command_register("time/stop", "", 0, 0, timeval_stop_cb, NULL); |
74467d5c | 822 | unixctl_command_register("time/warp", "[large_msecs] msecs", 1, 2, |
6197af6e BP |
823 | timeval_warp_cb, NULL); |
824 | } | |
2b31d8e7 PI |
825 | |
826 | ||
827 | ||
828 | /* strftime() with an extension for high-resolution timestamps. Any '#'s in | |
829 | * 'format' will be replaced by subseconds, e.g. use "%S.###" to obtain results | |
830 | * like "01.123". */ | |
831 | size_t | |
832 | strftime_msec(char *s, size_t max, const char *format, | |
833 | const struct tm_msec *tm) | |
834 | { | |
835 | size_t n; | |
836 | ||
2b89438d GS |
837 | /* Visual Studio 2013's behavior is to crash when 0 is passed as second |
838 | * argument to strftime. */ | |
839 | n = max ? strftime(s, max, format, &tm->tm) : 0; | |
2b31d8e7 PI |
840 | if (n) { |
841 | char decimals[4]; | |
842 | char *p; | |
843 | ||
844 | sprintf(decimals, "%03d", tm->msec); | |
845 | for (p = strchr(s, '#'); p; p = strchr(p, '#')) { | |
846 | char *d = decimals; | |
847 | while (*p == '#') { | |
848 | *p++ = *d ? *d++ : '0'; | |
849 | } | |
850 | } | |
851 | } | |
852 | ||
853 | return n; | |
854 | } | |
855 | ||
856 | struct tm_msec * | |
857 | localtime_msec(long long int now, struct tm_msec *result) | |
858 | { | |
859 | time_t now_sec = now / 1000; | |
860 | localtime_r(&now_sec, &result->tm); | |
861 | result->msec = now % 1000; | |
862 | return result; | |
863 | } | |
864 | ||
865 | struct tm_msec * | |
866 | gmtime_msec(long long int now, struct tm_msec *result) | |
867 | { | |
868 | time_t now_sec = now / 1000; | |
869 | gmtime_r(&now_sec, &result->tm); | |
870 | result->msec = now % 1000; | |
871 | return result; | |
872 | } |