2009-07-08 13:19:16 -07:00
|
|
|
|
/*
|
2012-05-25 13:54:38 -07:00
|
|
|
|
* Copyright (c) 2008, 2009, 2010, 2011, 2012 Nicira, Inc.
|
2009-07-08 13:19:16 -07:00
|
|
|
|
*
|
2009-06-15 15:11:30 -07:00
|
|
|
|
* Licensed under the Apache License, Version 2.0 (the "License");
|
|
|
|
|
* you may not use this file except in compliance with the License.
|
|
|
|
|
* You may obtain a copy of the License at:
|
2009-07-08 13:19:16 -07:00
|
|
|
|
*
|
2009-06-15 15:11:30 -07:00
|
|
|
|
* http://www.apache.org/licenses/LICENSE-2.0
|
|
|
|
|
*
|
|
|
|
|
* Unless required by applicable law or agreed to in writing, software
|
|
|
|
|
* distributed under the License is distributed on an "AS IS" BASIS,
|
|
|
|
|
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
|
|
|
|
* See the License for the specific language governing permissions and
|
|
|
|
|
* limitations under the License.
|
2009-07-08 13:19:16 -07:00
|
|
|
|
*/
|
|
|
|
|
|
|
|
|
|
#include <config.h>
|
|
|
|
|
#include "poll-loop.h"
|
|
|
|
|
#include <errno.h>
|
2009-11-06 10:43:50 -08:00
|
|
|
|
#include <inttypes.h>
|
2009-07-08 13:19:16 -07:00
|
|
|
|
#include <poll.h>
|
|
|
|
|
#include <stdlib.h>
|
|
|
|
|
#include <string.h>
|
|
|
|
|
#include "coverage.h"
|
|
|
|
|
#include "dynamic-string.h"
|
2009-12-08 14:11:22 -08:00
|
|
|
|
#include "fatal-signal.h"
|
2009-07-08 13:19:16 -07:00
|
|
|
|
#include "list.h"
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
#include "socket-util.h"
|
2009-07-08 13:19:16 -07:00
|
|
|
|
#include "timeval.h"
|
|
|
|
|
#include "vlog.h"
|
|
|
|
|
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
#undef poll_fd_wait
|
|
|
|
|
#undef poll_timer_wait
|
|
|
|
|
#undef poll_timer_wait_until
|
|
|
|
|
#undef poll_immediate_wake
|
|
|
|
|
|
2010-10-19 14:47:01 -07:00
|
|
|
|
VLOG_DEFINE_THIS_MODULE(poll_loop);
|
2010-07-16 11:02:49 -07:00
|
|
|
|
|
coverage: Make the coverage counters catalog program-specific.
Until now, the collection of coverage counters supported by a given OVS
program was not specific to that program. That means that, for example,
even though ovs-dpctl does not have anything to do with mac_learning, it
still has a coverage counter for it. This is confusing, at best.
This commit fixes the problem on some systems, in particular on ones that
use GCC and the GNU linker. It uses the feature of the GNU linker
described in its manual as:
If an orphaned section's name is representable as a C identifier then
the linker will automatically see PROVIDE two symbols: __start_SECNAME
and __end_SECNAME, where SECNAME is the name of the section. These
indicate the start address and end address of the orphaned section
respectively.
Systems that don't support these features retain the earlier behavior.
This commit also fixes the annoyance that files that include coverage
counters must be listed on COVERAGE_FILES in lib/automake.mk.
This commit also fixes the annoyance that modifying any source file that
includes a coverage counter caused all programs that link against
libopenvswitch.a to relink, even programs that the source file was not
linked into. For example, modifying ofproto/ofproto.c (which includes
coverage counters) caused tests/test-aes128 to relink, even though
test-aes128 does not link again ofproto.o.
2010-11-01 14:14:27 -07:00
|
|
|
|
COVERAGE_DEFINE(poll_fd_wait);
|
|
|
|
|
COVERAGE_DEFINE(poll_zero_timeout);
|
|
|
|
|
|
2009-07-08 13:19:16 -07:00
|
|
|
|
/* An event that will wake the following call to poll_block(). */
|
|
|
|
|
struct poll_waiter {
|
|
|
|
|
/* Set when the waiter is created. */
|
|
|
|
|
struct list node; /* Element in global waiters list. */
|
|
|
|
|
int fd; /* File descriptor. */
|
|
|
|
|
short int events; /* Events to wait for (POLLIN, POLLOUT). */
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
const char *where; /* Where the waiter was created. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
|
|
|
|
/* Set only when poll_block() is called. */
|
2009-12-18 16:15:01 -08:00
|
|
|
|
struct pollfd *pollfd; /* Pointer to element of the pollfds array. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
};
|
|
|
|
|
|
|
|
|
|
/* All active poll waiters. */
|
|
|
|
|
static struct list waiters = LIST_INITIALIZER(&waiters);
|
|
|
|
|
|
2011-12-19 14:28:42 -08:00
|
|
|
|
/* Time at which to wake up the next call to poll_block(), in milliseconds as
|
|
|
|
|
* returned by time_msec(), LLONG_MIN to wake up immediately, or LLONG_MAX to
|
2009-07-08 13:19:16 -07:00
|
|
|
|
* wait forever. */
|
2011-12-19 14:28:42 -08:00
|
|
|
|
static long long int timeout_when = LLONG_MAX;
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
/* Location where waiter created. */
|
|
|
|
|
static const char *timeout_where;
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
static struct poll_waiter *new_waiter(int fd, short int events,
|
|
|
|
|
const char *where);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
|
|
|
|
/* Registers 'fd' as waiting for the specified 'events' (which should be POLLIN
|
|
|
|
|
* or POLLOUT or POLLIN | POLLOUT). The following call to poll_block() will
|
|
|
|
|
* wake up when 'fd' becomes ready for one or more of the requested events.
|
|
|
|
|
*
|
|
|
|
|
* The event registration is one-shot: only the following call to poll_block()
|
|
|
|
|
* is affected. The event will need to be re-registered after poll_block() is
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
* called if it is to persist.
|
|
|
|
|
*
|
|
|
|
|
* Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
|
|
|
|
|
* for more information. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
struct poll_waiter *
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
poll_fd_wait(int fd, short int events, const char *where)
|
2009-07-08 13:19:16 -07:00
|
|
|
|
{
|
|
|
|
|
COVERAGE_INC(poll_fd_wait);
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
return new_waiter(fd, events, where);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Causes the following call to poll_block() to block for no more than 'msec'
|
|
|
|
|
* milliseconds. If 'msec' is nonpositive, the following call to poll_block()
|
|
|
|
|
* will not block at all.
|
|
|
|
|
*
|
|
|
|
|
* The timer registration is one-shot: only the following call to poll_block()
|
|
|
|
|
* is affected. The timer will need to be re-registered after poll_block() is
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
* called if it is to persist.
|
|
|
|
|
*
|
|
|
|
|
* Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
|
|
|
|
|
* for more information. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
void
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
poll_timer_wait(long long int msec, const char *where)
|
2009-07-08 13:19:16 -07:00
|
|
|
|
{
|
2011-12-19 14:28:42 -08:00
|
|
|
|
long long int now = time_msec();
|
|
|
|
|
long long int when;
|
|
|
|
|
|
|
|
|
|
if (msec <= 0) {
|
|
|
|
|
/* Wake up immediately. */
|
|
|
|
|
when = LLONG_MIN;
|
|
|
|
|
} else if ((unsigned long long int) now + msec <= LLONG_MAX) {
|
|
|
|
|
/* Normal case. */
|
|
|
|
|
when = now + msec;
|
|
|
|
|
} else {
|
|
|
|
|
/* now + msec would overflow. */
|
|
|
|
|
when = LLONG_MAX;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
poll_timer_wait_until(when, where);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
2010-05-12 12:53:07 -07:00
|
|
|
|
/* Causes the following call to poll_block() to wake up when the current time,
|
2011-12-19 14:28:42 -08:00
|
|
|
|
* as returned by time_msec(), reaches 'when' or later. If 'when' is earlier
|
2010-05-12 12:53:07 -07:00
|
|
|
|
* than the current time, the following call to poll_block() will not block at
|
|
|
|
|
* all.
|
|
|
|
|
*
|
|
|
|
|
* The timer registration is one-shot: only the following call to poll_block()
|
|
|
|
|
* is affected. The timer will need to be re-registered after poll_block() is
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
* called if it is to persist.
|
|
|
|
|
*
|
|
|
|
|
* Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
|
|
|
|
|
* for more information. */
|
2010-05-12 12:53:07 -07:00
|
|
|
|
void
|
2011-12-19 14:28:42 -08:00
|
|
|
|
poll_timer_wait_until(long long int when, const char *where)
|
2010-05-12 12:53:07 -07:00
|
|
|
|
{
|
2011-12-19 14:28:42 -08:00
|
|
|
|
if (when < timeout_when) {
|
|
|
|
|
timeout_when = when;
|
|
|
|
|
timeout_where = where;
|
|
|
|
|
}
|
2010-05-12 12:53:07 -07:00
|
|
|
|
}
|
|
|
|
|
|
2009-07-08 13:19:16 -07:00
|
|
|
|
/* Causes the following call to poll_block() to wake up immediately, without
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
* blocking.
|
|
|
|
|
*
|
|
|
|
|
* Ordinarily the 'where' argument is supplied automatically; see poll-loop.h
|
|
|
|
|
* for more information. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
void
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
poll_immediate_wake(const char *where)
|
2009-07-08 13:19:16 -07:00
|
|
|
|
{
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
poll_timer_wait(0, where);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
2011-05-24 12:23:42 -07:00
|
|
|
|
/* Logs, if appropriate, that the poll loop was awakened by an event
|
|
|
|
|
* registered at 'where' (typically a source file and line number). The other
|
|
|
|
|
* arguments have two possible interpretations:
|
|
|
|
|
*
|
|
|
|
|
* - If 'pollfd' is nonnull then it should be the "struct pollfd" that caused
|
2011-05-27 09:13:50 -07:00
|
|
|
|
* the wakeup. 'timeout' is ignored.
|
2011-05-24 12:23:42 -07:00
|
|
|
|
*
|
2011-05-27 09:13:50 -07:00
|
|
|
|
* - If 'pollfd' is NULL then 'timeout' is the number of milliseconds after
|
|
|
|
|
* which the poll loop woke up.
|
2011-05-24 12:23:42 -07:00
|
|
|
|
*/
|
|
|
|
|
static void
|
|
|
|
|
log_wakeup(const char *where, const struct pollfd *pollfd, int timeout)
|
2009-07-08 13:19:16 -07:00
|
|
|
|
{
|
2012-10-22 16:53:54 -07:00
|
|
|
|
static struct vlog_rate_limit trace_rl = VLOG_RATE_LIMIT_INIT(1, 1);
|
2012-05-25 13:54:38 -07:00
|
|
|
|
static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(10, 10);
|
2011-05-24 12:23:42 -07:00
|
|
|
|
enum vlog_level level;
|
|
|
|
|
int cpu_usage;
|
|
|
|
|
struct ds s;
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
2011-05-24 12:23:42 -07:00
|
|
|
|
cpu_usage = get_cpu_usage();
|
|
|
|
|
if (VLOG_IS_DBG_ENABLED()) {
|
|
|
|
|
level = VLL_DBG;
|
2012-08-20 10:52:26 -07:00
|
|
|
|
} else if (cpu_usage > 50 && !VLOG_DROP_INFO(&rl)) {
|
|
|
|
|
level = VLL_INFO;
|
2011-05-24 12:23:42 -07:00
|
|
|
|
} else {
|
|
|
|
|
return;
|
|
|
|
|
}
|
2009-07-08 13:19:16 -07:00
|
|
|
|
|
2011-05-24 12:23:42 -07:00
|
|
|
|
ds_init(&s);
|
|
|
|
|
ds_put_cstr(&s, "wakeup due to ");
|
|
|
|
|
if (pollfd) {
|
|
|
|
|
char *description = describe_fd(pollfd->fd);
|
|
|
|
|
if (pollfd->revents & POLLIN) {
|
|
|
|
|
ds_put_cstr(&s, "[POLLIN]");
|
|
|
|
|
}
|
|
|
|
|
if (pollfd->revents & POLLOUT) {
|
|
|
|
|
ds_put_cstr(&s, "[POLLOUT]");
|
|
|
|
|
}
|
|
|
|
|
if (pollfd->revents & POLLERR) {
|
|
|
|
|
ds_put_cstr(&s, "[POLLERR]");
|
|
|
|
|
}
|
|
|
|
|
if (pollfd->revents & POLLHUP) {
|
|
|
|
|
ds_put_cstr(&s, "[POLLHUP]");
|
|
|
|
|
}
|
|
|
|
|
if (pollfd->revents & POLLNVAL) {
|
|
|
|
|
ds_put_cstr(&s, "[POLLNVAL]");
|
|
|
|
|
}
|
|
|
|
|
ds_put_format(&s, " on fd %d (%s)", pollfd->fd, description);
|
|
|
|
|
free(description);
|
|
|
|
|
} else {
|
|
|
|
|
ds_put_format(&s, "%d-ms timeout", timeout);
|
|
|
|
|
}
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
if (where) {
|
2011-05-24 12:23:42 -07:00
|
|
|
|
ds_put_format(&s, " at %s", where);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
2011-05-24 12:23:42 -07:00
|
|
|
|
if (cpu_usage >= 0) {
|
|
|
|
|
ds_put_format(&s, " (%d%% CPU usage)", cpu_usage);
|
2012-10-22 16:53:54 -07:00
|
|
|
|
|
|
|
|
|
if (!vlog_should_drop(THIS_MODULE, level, &trace_rl)) {
|
|
|
|
|
ds_put_char(&s, '\n');
|
|
|
|
|
format_backtraces(&s, 2);
|
|
|
|
|
}
|
2011-05-24 12:23:42 -07:00
|
|
|
|
}
|
|
|
|
|
VLOG(level, "%s", ds_cstr(&s));
|
|
|
|
|
ds_destroy(&s);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Blocks until one or more of the events registered with poll_fd_wait()
|
|
|
|
|
* occurs, or until the minimum duration registered with poll_timer_wait()
|
2009-12-18 16:15:01 -08:00
|
|
|
|
* elapses, or not at all if poll_immediate_wake() has been called. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
void
|
|
|
|
|
poll_block(void)
|
|
|
|
|
{
|
2011-11-22 11:05:53 -08:00
|
|
|
|
static struct pollfd *pollfds;
|
|
|
|
|
static size_t max_pollfds;
|
|
|
|
|
|
2009-12-18 16:15:01 -08:00
|
|
|
|
struct poll_waiter *pw, *next;
|
2011-11-22 11:05:53 -08:00
|
|
|
|
int n_waiters, n_pollfds;
|
2011-12-19 14:28:42 -08:00
|
|
|
|
int elapsed;
|
2009-07-08 13:19:16 -07:00
|
|
|
|
int retval;
|
|
|
|
|
|
2009-12-08 14:11:22 -08:00
|
|
|
|
/* Register fatal signal events before actually doing any real work for
|
|
|
|
|
* poll_block. */
|
|
|
|
|
fatal_signal_wait();
|
|
|
|
|
|
2011-08-10 12:49:35 -07:00
|
|
|
|
n_waiters = list_size(&waiters);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
if (max_pollfds < n_waiters) {
|
|
|
|
|
max_pollfds = n_waiters;
|
|
|
|
|
pollfds = xrealloc(pollfds, max_pollfds * sizeof *pollfds);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
n_pollfds = 0;
|
2010-09-17 10:33:10 -07:00
|
|
|
|
LIST_FOR_EACH (pw, node, &waiters) {
|
2009-07-08 13:19:16 -07:00
|
|
|
|
pw->pollfd = &pollfds[n_pollfds];
|
|
|
|
|
pollfds[n_pollfds].fd = pw->fd;
|
|
|
|
|
pollfds[n_pollfds].events = pw->events;
|
|
|
|
|
pollfds[n_pollfds].revents = 0;
|
|
|
|
|
n_pollfds++;
|
|
|
|
|
}
|
|
|
|
|
|
2011-12-19 14:28:42 -08:00
|
|
|
|
if (timeout_when == LLONG_MIN) {
|
2009-07-08 13:19:16 -07:00
|
|
|
|
COVERAGE_INC(poll_zero_timeout);
|
|
|
|
|
}
|
2011-12-19 14:28:42 -08:00
|
|
|
|
retval = time_poll(pollfds, n_pollfds, timeout_when, &elapsed);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
if (retval < 0) {
|
|
|
|
|
static struct vlog_rate_limit rl = VLOG_RATE_LIMIT_INIT(1, 5);
|
|
|
|
|
VLOG_ERR_RL(&rl, "poll: %s", strerror(-retval));
|
2011-05-24 12:23:42 -07:00
|
|
|
|
} else if (!retval) {
|
2011-12-19 14:28:42 -08:00
|
|
|
|
log_wakeup(timeout_where, NULL, elapsed);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
2010-09-17 10:33:10 -07:00
|
|
|
|
LIST_FOR_EACH_SAFE (pw, next, node, &waiters) {
|
2011-05-24 12:23:42 -07:00
|
|
|
|
if (pw->pollfd->revents) {
|
|
|
|
|
log_wakeup(pw->where, pw->pollfd, 0);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
poll_cancel(pw);
|
|
|
|
|
}
|
|
|
|
|
|
2011-12-19 14:28:42 -08:00
|
|
|
|
timeout_when = LLONG_MAX;
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
timeout_where = NULL;
|
2009-12-08 14:11:22 -08:00
|
|
|
|
|
|
|
|
|
/* Handle any pending signals before doing anything else. */
|
|
|
|
|
fatal_signal_run();
|
2009-07-08 13:19:16 -07:00
|
|
|
|
}
|
|
|
|
|
|
2009-12-18 16:15:01 -08:00
|
|
|
|
/* Cancels the file descriptor event registered with poll_fd_wait() using 'pw',
|
|
|
|
|
* the struct poll_waiter returned by that function.
|
2009-07-08 13:19:16 -07:00
|
|
|
|
*
|
|
|
|
|
* An event registered with poll_fd_wait() may be canceled from its time of
|
|
|
|
|
* registration until the next call to poll_block(). At that point, the event
|
2009-12-18 16:15:01 -08:00
|
|
|
|
* is automatically canceled by the system and its poll_waiter is freed. */
|
2009-07-08 13:19:16 -07:00
|
|
|
|
void
|
|
|
|
|
poll_cancel(struct poll_waiter *pw)
|
|
|
|
|
{
|
|
|
|
|
if (pw) {
|
|
|
|
|
list_remove(&pw->node);
|
|
|
|
|
free(pw);
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Creates and returns a new poll_waiter for 'fd' and 'events'. */
|
|
|
|
|
static struct poll_waiter *
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
new_waiter(int fd, short int events, const char *where)
|
2009-07-08 13:19:16 -07:00
|
|
|
|
{
|
2009-09-28 13:56:42 -07:00
|
|
|
|
struct poll_waiter *waiter = xzalloc(sizeof *waiter);
|
2012-11-06 13:14:55 -08:00
|
|
|
|
ovs_assert(fd >= 0);
|
2009-07-08 13:19:16 -07:00
|
|
|
|
waiter->fd = fd;
|
|
|
|
|
waiter->events = events;
|
poll-loop: Make wakeup logging more portable and easier to understand.
Until now, when the poll_loop module's log level was turned up to "debug",
it would log a backtrace of the call stack for the event that caused poll()
to wake up in poll_block(). This was pretty useful from time to time to
find out why ovs-vswitchd was using more CPU than expected, because we
could find out what was causing it to wake up.
But there were some issues. One is simply that the backtrace was printed
as a series of hexadecimal numbers, so GDB or another debugger was needed
to translate it into human-readable format. Compiler optimizations meant
that even the human-readable backtrace wasn't, in my experience, as helpful
as it could have been. And, of course, one needed to have the binary to
interpret the backtrace. When the backtrace couldn't be interpreted or
wasn't meaningful, there was essentially nothing to fall back on.
This commit changes the way that "debug" logging for poll_block() wakeups
works. Instead of logging a backtrace, it logs the source code file name
and line number of the call to a poll_loop function, using __FILE__ and
__LINE__. This is by itself much more meaningful than a sequence of
hexadecimal numbers, since no additional interpretation is necessary. It
can be useful even if the Open vSwitch version is only approximately known.
In addition to the file and line, this commit adds, for wakeups caused by
file descriptors, information about the file descriptor itself: what kind
of file it is (regular file, directory, socket, etc.), the name of the file
(on Linux only), and the local and remote endpoints for socket file
descriptors.
Here are a few examples of the new output format:
932-ms timeout at ../ofproto/in-band.c:507
[POLLIN] on fd 20 (192.168.0.20:35388<->192.168.0.3:6633) at ../lib/stream-fd.c:149
[POLLIN] on fd 7 (FIFO pipe:[48049]) at ../lib/fatal-signal.c:168
2011-05-13 13:06:49 -07:00
|
|
|
|
waiter->where = where;
|
2009-07-08 13:19:16 -07:00
|
|
|
|
list_push_back(&waiters, &waiter->node);
|
|
|
|
|
return waiter;
|
|
|
|
|
}
|