poll-loop: More strictly rate-limit high CPU use logging.
[openvswitch] / lib / poll-loop.c
1 /*
2  * Copyright (c) 2008, 2009, 2010, 2011, 2012 Nicira, Inc.
3  *
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:
7  *
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.
15  */
16
17 #include <config.h>
18 #include "poll-loop.h"
19 #include <assert.h>
20 #include <errno.h>
21 #include <inttypes.h>
22 #include <poll.h>
23 #include <stdlib.h>
24 #include <string.h>
25 #include "coverage.h"
26 #include "dynamic-string.h"
27 #include "fatal-signal.h"
28 #include "list.h"
29 #include "socket-util.h"
30 #include "timeval.h"
31 #include "vlog.h"
32
33 #undef poll_fd_wait
34 #undef poll_timer_wait
35 #undef poll_timer_wait_until
36 #undef poll_immediate_wake
37
38 VLOG_DEFINE_THIS_MODULE(poll_loop);
39
40 COVERAGE_DEFINE(poll_fd_wait);
41 COVERAGE_DEFINE(poll_zero_timeout);
42
43 /* An event that will wake the following call to poll_block(). */
44 struct poll_waiter {
45     /* Set when the waiter is created. */
46     struct list node;           /* Element in global waiters list. */
47     int fd;                     /* File descriptor. */
48     short int events;           /* Events to wait for (POLLIN, POLLOUT). */
49     const char *where;          /* Where the waiter was created. */
50
51     /* Set only when poll_block() is called. */
52     struct pollfd *pollfd;      /* Pointer to element of the pollfds array. */
53 };
54
55 /* All active poll waiters. */
56 static struct list waiters = LIST_INITIALIZER(&waiters);
57
58 /* Time at which to wake up the next call to poll_block(), in milliseconds as
59  * returned by time_msec(), LLONG_MIN to wake up immediately, or LLONG_MAX to
60  * wait forever. */
61 static long long int timeout_when = LLONG_MAX;
62
63 /* Location where waiter created. */
64 static const char *timeout_where;
65
66 static struct poll_waiter *new_waiter(int fd, short int events,
67                                       const char *where);
68
69 /* Registers 'fd' as waiting for the specified 'events' (which should be POLLIN
70  * or POLLOUT or POLLIN | POLLOUT).  The following call to poll_block() will
71  * wake up when 'fd' becomes ready for one or more of the requested events.
72  *
73  * The event registration is one-shot: only the following call to poll_block()
74  * is affected.  The event will need to be re-registered after poll_block() is
75  * called if it is to persist.
76  *
77  * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
78  * for more information. */
79 struct poll_waiter *
80 poll_fd_wait(int fd, short int events, const char *where)
81 {
82     COVERAGE_INC(poll_fd_wait);
83     return new_waiter(fd, events, where);
84 }
85
86 /* Causes the following call to poll_block() to block for no more than 'msec'
87  * milliseconds.  If 'msec' is nonpositive, the following call to poll_block()
88  * will not block at all.
89  *
90  * The timer registration is one-shot: only the following call to poll_block()
91  * is affected.  The timer will need to be re-registered after poll_block() is
92  * called if it is to persist.
93  *
94  * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
95  * for more information. */
96 void
97 poll_timer_wait(long long int msec, const char *where)
98 {
99     long long int now = time_msec();
100     long long int when;
101
102     if (msec <= 0) {
103         /* Wake up immediately. */
104         when = LLONG_MIN;
105     } else if ((unsigned long long int) now + msec <= LLONG_MAX) {
106         /* Normal case. */
107         when = now + msec;
108     } else {
109         /* now + msec would overflow. */
110         when = LLONG_MAX;
111     }
112
113     poll_timer_wait_until(when, where);
114 }
115
116 /* Causes the following call to poll_block() to wake up when the current time,
117  * as returned by time_msec(), reaches 'when' or later.  If 'when' is earlier
118  * than the current time, the following call to poll_block() will not block at
119  * all.
120  *
121  * The timer registration is one-shot: only the following call to poll_block()
122  * is affected.  The timer will need to be re-registered after poll_block() is
123  * called if it is to persist.
124  *
125  * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
126  * for more information. */
127 void
128 poll_timer_wait_until(long long int when, const char *where)
129 {
130     if (when < timeout_when) {
131         timeout_when = when;
132         timeout_where = where;
133     }
134 }
135
136 /* Causes the following call to poll_block() to wake up immediately, without
137  * blocking.
138  *
139  * Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
140  * for more information. */
141 void
142 poll_immediate_wake(const char *where)
143 {
144     poll_timer_wait(0, where);
145 }
146
147 /* Logs, if appropriate, that the poll loop was awakened by an event
148  * registered at 'where' (typically a source file and line number).  The other
149  * arguments have two possible interpretations:
150  *
151  *   - If 'pollfd' is nonnull then it should be the "struct pollfd" that caused
152  *     the wakeup.  'timeout' is ignored.
153  *
154  *   - If 'pollfd' is NULL then 'timeout' is the number of milliseconds after
155  *     which the poll loop woke up.
156  */
157 static void
158 log_wakeup(const char *where, const struct pollfd *pollfd, int timeout)
159 {
160     static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(10, 10);
161     enum vlog_level level;
162     int cpu_usage;
163     struct ds s;
164
165     cpu_usage = get_cpu_usage();
166     if (VLOG_IS_DBG_ENABLED()) {
167         level = VLL_DBG;
168     } else if (cpu_usage > 50 && !VLOG_DROP_WARN(&rl)) {
169         level = VLL_WARN;
170     } else {
171         return;
172     }
173
174     ds_init(&s);
175     ds_put_cstr(&s, "wakeup due to ");
176     if (pollfd) {
177         char *description = describe_fd(pollfd->fd);
178         if (pollfd->revents & POLLIN) {
179             ds_put_cstr(&s, "[POLLIN]");
180         }
181         if (pollfd->revents & POLLOUT) {
182             ds_put_cstr(&s, "[POLLOUT]");
183         }
184         if (pollfd->revents & POLLERR) {
185             ds_put_cstr(&s, "[POLLERR]");
186         }
187         if (pollfd->revents & POLLHUP) {
188             ds_put_cstr(&s, "[POLLHUP]");
189         }
190         if (pollfd->revents & POLLNVAL) {
191             ds_put_cstr(&s, "[POLLNVAL]");
192         }
193         ds_put_format(&s, " on fd %d (%s)", pollfd->fd, description);
194         free(description);
195     } else {
196         ds_put_format(&s, "%d-ms timeout", timeout);
197     }
198     if (where) {
199         ds_put_format(&s, " at %s", where);
200     }
201     if (cpu_usage >= 0) {
202         ds_put_format(&s, " (%d%% CPU usage)", cpu_usage);
203     }
204     VLOG(level, "%s", ds_cstr(&s));
205     ds_destroy(&s);
206 }
207
208 /* Blocks until one or more of the events registered with poll_fd_wait()
209  * occurs, or until the minimum duration registered with poll_timer_wait()
210  * elapses, or not at all if poll_immediate_wake() has been called. */
211 void
212 poll_block(void)
213 {
214     static struct pollfd *pollfds;
215     static size_t max_pollfds;
216
217     struct poll_waiter *pw, *next;
218     int n_waiters, n_pollfds;
219     int elapsed;
220     int retval;
221
222     /* Register fatal signal events before actually doing any real work for
223      * poll_block. */
224     fatal_signal_wait();
225
226     n_waiters = list_size(&waiters);
227     if (max_pollfds < n_waiters) {
228         max_pollfds = n_waiters;
229         pollfds = xrealloc(pollfds, max_pollfds * sizeof *pollfds);
230     }
231
232     n_pollfds = 0;
233     LIST_FOR_EACH (pw, node, &waiters) {
234         pw->pollfd = &pollfds[n_pollfds];
235         pollfds[n_pollfds].fd = pw->fd;
236         pollfds[n_pollfds].events = pw->events;
237         pollfds[n_pollfds].revents = 0;
238         n_pollfds++;
239     }
240
241     if (timeout_when == LLONG_MIN) {
242         COVERAGE_INC(poll_zero_timeout);
243     }
244     retval = time_poll(pollfds, n_pollfds, timeout_when, &elapsed);
245     if (retval < 0) {
246         static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
247         VLOG_ERR_RL(&rl, "poll: %s", strerror(-retval));
248     } else if (!retval) {
249         log_wakeup(timeout_where, NULL, elapsed);
250     }
251
252     LIST_FOR_EACH_SAFE (pw, next, node, &waiters) {
253         if (pw->pollfd->revents) {
254             log_wakeup(pw->where, pw->pollfd, 0);
255         }
256         poll_cancel(pw);
257     }
258
259     timeout_when = LLONG_MAX;
260     timeout_where = NULL;
261
262     /* Handle any pending signals before doing anything else. */
263     fatal_signal_run();
264 }
265
266 /* Cancels the file descriptor event registered with poll_fd_wait() using 'pw',
267  * the struct poll_waiter returned by that function.
268  *
269  * An event registered with poll_fd_wait() may be canceled from its time of
270  * registration until the next call to poll_block().  At that point, the event
271  * is automatically canceled by the system and its poll_waiter is freed. */
272 void
273 poll_cancel(struct poll_waiter *pw)
274 {
275     if (pw) {
276         list_remove(&pw->node);
277         free(pw);
278     }
279 }
280 \f
281 /* Creates and returns a new poll_waiter for 'fd' and 'events'. */
282 static struct poll_waiter *
283 new_waiter(int fd, short int events, const char *where)
284 {
285     struct poll_waiter *waiter = xzalloc(sizeof *waiter);
286     assert(fd >= 0);
287     waiter->fd = fd;
288     waiter->events = events;
289     waiter->where = where;
290     list_push_back(&waiters, &waiter->node);
291     return waiter;
292 }