Skip to content

Commit

Permalink
Implement logging of file descriptor opening and closing
Browse files Browse the repository at this point in the history
  • Loading branch information
@FooBarWidget
FooBarWidget committed Mar 23, 2015
1 parent 1fc3dbe commit a84b6ae
Show file tree
Hide file tree
Showing 56 changed files with 896 additions and 471 deletions.
10 changes: 10 additions & 0 deletions .editorconfig
View file
Original file line number Diff line number Diff line change
Expand Up @@ -76,6 +76,16 @@ indent_size = 4
indent_style = space
indent_size = 4

[ext/libev/*.c]
indent_style = space
indent_size = 2
trim_trailing_whitespace = false

[ext/libev/*.h]
indent_style = space
indent_size = 2
trim_trailing_whitespace = false

[ext/libeio/*.c]
indent_style = space
indent_size = 2
Expand Down
3 changes: 0 additions & 3 deletions debian.template/control.erb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,9 +15,6 @@ Build-Depends: debhelper (>= 7.0.50~), rake,
ruby2.0, ruby2.0-dev,
<% end -%>
apache2-mpm-worker | apache2-mpm, apache2-threaded-dev,
<% if is_distribution?('>= precise') || is_distribution?('>= wheezy') -%>
libev-dev (>= 1:4.0.0),
<% end -%>
libapr1-dev, libcurl4-openssl-dev
Standards-Version: 3.9.3
Homepage: https://www.phusionpassenger.com/
Expand Down
4 changes: 0 additions & 4 deletions debian.template/rules.erb
View file
Original file line number Diff line number Diff line change
@@ -1,10 +1,6 @@
#!/usr/bin/make -f
# export DH_VERBOSE=1

<% if is_distribution?('>= precise') || is_distribution?('>= wheezy') -%>
export USE_VENDORED_LIBEV=false
<% end %>

<% if ['1', 'true', 'on', 'yes'].include?(ENV['USE_CCACHE']) -%>
export USE_CCACHE=1
NGINX_CONFIGURE_OPTIONS = CC=/usr/lib/ccache/cc CXX=/usr/lib/ccache/c++
Expand Down
6 changes: 3 additions & 3 deletions ext/apache2/Hooks.cpp
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2010-2014 Phusion
* Copyright (c) 2010-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -246,7 +246,7 @@ class Hooks {
FileDescriptor conn;

try {
conn = connectToServer(getServerAddress());
conn.assign(connectToServer(getServerAddress(), __FILE__, __LINE__), NULL, 0);
} catch (const SystemException &e) {
if (e.code() == EPIPE || e.code() == ECONNREFUSED || e.code() == ENOENT) {
UPDATE_TRACE_POINT();
Expand All @@ -260,7 +260,7 @@ class Hooks {
time_t deadline = time(NULL) + 5;
while (!connected && time(NULL) < deadline) {
try {
conn = connectToServer(getServerAddress());
conn.assign(connectToServer(getServerAddress(), __FILE__, __LINE__), NULL, 0);
connected = true;
} catch (const SystemException &e) {
if (e.code() == EPIPE || e.code() == ECONNREFUSED || e.code() == ENOENT) {
Expand Down
5 changes: 3 additions & 2 deletions ext/common/AgentsStarter.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2010-2014 Phusion
* Copyright (c) 2010-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -326,7 +326,7 @@ class AgentsStarter {
.setInt ("log_level", getLogLevel());
extraParams.addTo(params);

fds = createUnixSocketPair();
fds = createUnixSocketPair(__FILE__, __LINE__);
pid = syscalls::fork();
if (pid == 0) {
// Child
Expand Down Expand Up @@ -388,6 +388,7 @@ class AgentsStarter {

ScopeGuard guard(boost::bind(&AgentsStarter::killProcessGroupAndWait, &pid, 0));
fds[1].close();
P_LOG_FILE_DESCRIPTOR_PURPOSE(feedbackFd, "AgentsStarter: feedback FD");


/****** Send arguments to watchdog through the feedback channel ******/
Expand Down
16 changes: 13 additions & 3 deletions ext/common/ApplicationPool2/DirectSpawner.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011-2014 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -160,8 +160,8 @@ class DirectSpawner: public Spawner {
shared_array<const char *> args;
SpawnPreparationInfo preparation = prepareSpawn(options);
vector<string> command = createCommand(options, preparation, args);
SocketPair adminSocket = createUnixSocketPair();
Pipe errorPipe = createPipe();
SocketPair adminSocket = createUnixSocketPair(__FILE__, __LINE__);
Pipe errorPipe = createPipe(__FILE__, __LINE__);
DebugDirPtr debugDir = boost::make_shared<DebugDir>(preparation.uid, preparation.gid);
pid_t pid;

Expand Down Expand Up @@ -199,6 +199,16 @@ class DirectSpawner: public Spawner {
throw SystemException("Cannot fork a new process", e);

} else {
UPDATE_TRACE_POINT();
P_LOG_FILE_DESCRIPTOR_PURPOSE(adminSocket.first,
"App " << pid << " (" << options.appRoot << ") adminSocket[0]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(adminSocket.second,
"App " << pid << " (" << options.appRoot << ") adminSocket[1]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(errorPipe.first,
"App " << pid << " (" << options.appRoot << ") errorPipe[0]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(errorPipe.second,
"App " << pid << " (" << options.appRoot << ") errorPipe[1]");

UPDATE_TRACE_POINT();
ScopeGuard guard(boost::bind(nonInterruptableKillAndWaitpid, pid));
P_DEBUG("Process forked for appRoot=" << options.appRoot << ": PID " << pid);
Expand Down
19 changes: 12 additions & 7 deletions ext/common/ApplicationPool2/DummySpawner.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011-2014 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -54,17 +54,22 @@ class DummySpawner: public Spawner {
TRACE_POINT();
possiblyRaiseInternalError(options);

SocketPair adminSocket = createUnixSocketPair();
pid_t pid;
{
boost::lock_guard<boost::mutex> l(lock);
count++;
pid = count;
}

SocketPair adminSocket = createUnixSocketPair(__FILE__, __LINE__);
SocketList sockets;
sockets.add("main", "tcp://127.0.0.1:1234", "session", config->concurrency);
sockets.add(pid, "main", "tcp://127.0.0.1:1234", "session", config->concurrency);
syscalls::usleep(config->spawnTime);

boost::lock_guard<boost::mutex> l(lock);
count++;
SpawnObject object;
string gupid = "gupid-" + toString(count);
string gupid = "gupid-" + toString(pid);
object.process = boost::make_shared<Process>(
(pid_t) count, gupid,
pid, gupid,
adminSocket.second, FileDescriptor(), sockets,
SystemTime::getUsec(), SystemTime::getUsec());
object.process->dummy = true;
Expand Down
2 changes: 1 addition & 1 deletion ext/common/ApplicationPool2/Implementation.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -198,7 +198,7 @@ void processAndLogNewSpawnException(SpawnException &e, const Options &options,
getSystemTempDir());
fd = mkstemp(filename);
#endif
FdGuard guard(fd, true);
FdGuard guard(fd, NULL, 0, true);
if (fd == -1) {
int e = errno;
throw SystemException("Cannot generate a temporary filename",
Expand Down
4 changes: 2 additions & 2 deletions ext/common/ApplicationPool2/Session.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011-2014 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -150,7 +150,7 @@ class Session {
Connection connection = socket->checkoutConnection();
connection.fail = true;
if (connection.blocking && !blocking) {
FdGuard g2(connection.fd);
FdGuard g2(connection.fd, NULL, 0);
setNonBlocking(connection.fd);
g2.clear();
connection.blocking = false;
Expand Down
21 changes: 18 additions & 3 deletions ext/common/ApplicationPool2/SmartSpawner.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -212,8 +212,8 @@ class SmartSpawner: public Spawner, public boost::enable_shared_from_this<SmartS
shared_array<const char *> args;
preparation = prepareSpawn(options);
vector<string> command = createRealPreloaderCommand(options, args);
SocketPair adminSocket = createUnixSocketPair();
Pipe errorPipe = createPipe();
SocketPair adminSocket = createUnixSocketPair(__FILE__, __LINE__);
Pipe errorPipe = createPipe(__FILE__, __LINE__);
DebugDirPtr debugDir = boost::make_shared<DebugDir>(preparation.uid, preparation.gid);
pid_t pid;

Expand Down Expand Up @@ -251,6 +251,17 @@ class SmartSpawner: public Spawner, public boost::enable_shared_from_this<SmartS
throw SystemException("Cannot fork a new process", e);

} else {
UPDATE_TRACE_POINT();
P_LOG_FILE_DESCRIPTOR_PURPOSE(adminSocket.first,
"Preloader " << pid << " (" << options.appRoot << ") adminSocket[0]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(adminSocket.second,
"Preloader " << pid << " (" << options.appRoot << ") adminSocket[1]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(errorPipe.first,
"Preloader " << pid << " (" << options.appRoot << ") errorPipe[0]");
P_LOG_FILE_DESCRIPTOR_PURPOSE(errorPipe.second,
"Preloader " << pid << " (" << options.appRoot << ") errorPipe[1]");

UPDATE_TRACE_POINT();
ScopeGuard guard(boost::bind(nonInterruptableKillAndWaitpid, pid));
P_DEBUG("Preloader process forked for appRoot=" << options.appRoot << ": PID " << pid);
adminSocket.first.close();
Expand Down Expand Up @@ -610,7 +621,7 @@ class SmartSpawner: public Spawner, public boost::enable_shared_from_this<SmartS
TRACE_POINT();
FileDescriptor fd;
try {
fd = connectToServer(socketAddress);
fd.assign(connectToServer(socketAddress, __FILE__, __LINE__), NULL, 0);
} catch (const SystemException &e) {
BackgroundIOCapturerPtr stderrCapturer;
throwPreloaderSpawnException("An error occurred while starting "
Expand All @@ -621,6 +632,8 @@ class SmartSpawner: public Spawner, public boost::enable_shared_from_this<SmartS
options,
DebugDirPtr());
}
P_LOG_FILE_DESCRIPTOR_PURPOSE(fd, "Preloader " << pid
<< " (" << options.appRoot << ") connection");

UPDATE_TRACE_POINT();
BufferedIO io(fd);
Expand Down Expand Up @@ -671,6 +684,8 @@ class SmartSpawner: public Spawner, public boost::enable_shared_from_this<SmartS
}

SpawnResult result;
P_LOG_FILE_DESCRIPTOR_PURPOSE(fd, "App " << spawnedPid
<< " (" << options.appRoot << ") adminSocket[1]");
result.pid = spawnedPid;
result.adminSocket = fd;
result.io = io;
Expand Down
22 changes: 16 additions & 6 deletions ext/common/ApplicationPool2/Socket.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011-2014 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -64,6 +64,7 @@ struct Connection {
fd = -1;
persistent = false;
safelyClose(fd2);
P_LOG_FILE_DESCRIPTOR_CLOSE(fd2);
}
}
};
Expand All @@ -85,10 +86,11 @@ class Socket {
Connection connect() const {
Connection connection;
P_TRACE(3, "Connecting to " << address);
connection.fd = connectToServer(address);
connection.fd = connectToServer(address, __FILE__, __LINE__);
connection.fail = true;
connection.persistent = false;
connection.blocking = true;
P_LOG_FILE_DESCRIPTOR_PURPOSE(connection.fd, "App " << pid << " connection");
return connection;
}

Expand All @@ -97,6 +99,7 @@ class Socket {
StaticString name;
StaticString address;
StaticString protocol;
pid_t pid;
int concurrency;

// Private. In public section as alignment optimization.
Expand All @@ -106,13 +109,16 @@ class Socket {
int sessions;

Socket()
: concurrency(0)
: pid(-1),
concurrency(0)
{ }

Socket(const StaticString &_name, const StaticString &_address, const StaticString &_protocol, int _concurrency)
Socket(pid_t _pid, const StaticString &_name, const StaticString &_address,
const StaticString &_protocol, int _concurrency)
: name(_name),
address(_address),
protocol(_protocol),
pid(_pid),
concurrency(_concurrency),
totalActiveConnections(0),
sessions(0)
Expand All @@ -123,6 +129,7 @@ class Socket {
name(other.name),
address(other.address),
protocol(other.protocol),
pid(other.pid),
concurrency(other.concurrency),
totalActiveConnections(other.totalActiveConnections),
sessions(other.sessions)
Expand All @@ -134,6 +141,7 @@ class Socket {
name = other.name;
address = other.address;
protocol = other.protocol;
pid = other.pid;
concurrency = other.concurrency;
sessions = other.sessions;
return *this;
Expand Down Expand Up @@ -226,8 +234,10 @@ class Socket {

class SocketList: public SmallVector<Socket, 1> {
public:
void add(const StaticString &name, const StaticString &address, const StaticString &protocol, int concurrency) {
push_back(Socket(name, address, protocol, concurrency));
void add(pid_t pid, const StaticString &name, const StaticString &address,
const StaticString &protocol, int concurrency)
{
push_back(Socket(pid, name, address, protocol, concurrency));
}

const Socket *findSocketWithName(const StaticString &name) const {
Expand Down
4 changes: 2 additions & 2 deletions ext/common/ApplicationPool2/Spawner.h
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011-2014 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -496,7 +496,7 @@ class Spawner {
fixupSocketAddress(*details.options, args[1]));
StaticString protocol = psg_pstrdup(result.pool, args[2]);

sockets.add(name, address, protocol, atoi(args[3]));
sockets.add(details.pid, name, address, protocol, atoi(args[3]));
} else {
throwAppSpawnException("An error occurred while starting the "
"web application. It reported a wrongly formatted 'socket'"
Expand Down
7 changes: 6 additions & 1 deletion ext/common/BackgroundEventLoop.cpp
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
/*
* Phusion Passenger - https://www.phusionpassenger.com/
* Copyright (c) 2011, 2012 Phusion
* Copyright (c) 2011-2015 Phusion
*
* "Phusion Passenger" is a trademark of Hongli Lai & Ninh Bui.
*
Expand Down Expand Up @@ -29,6 +29,7 @@
#include <ev++.h>
#include <eio.h>
#include <BackgroundEventLoop.h>
#include <Logging.h>
#include <Exceptions.h>
#include <SafeLibev.h>

Expand Down Expand Up @@ -107,10 +108,14 @@ BackgroundEventLoop::BackgroundEventLoop(bool scalable, bool useLibeio) {
throw RuntimeException("Cannot create an event loop");
}

P_LOG_FILE_DESCRIPTOR_OPEN2(ev_backend_fd(loop), "libev event loop: backend FD");

async = (ev_async *) malloc(sizeof(ev_async));
async->data = this;
ev_async_init(async, signalBackgroundEventLoopExit);
ev_async_start(loop, async);
P_LOG_FILE_DESCRIPTOR_OPEN2(ev_loop_get_pipe(loop, 0), "libev event loop: async pipe 0");
P_LOG_FILE_DESCRIPTOR_OPEN2(ev_loop_get_pipe(loop, 1), "libev event loop: async pipe 1");
safe = boost::make_shared<SafeLibev>(loop);
priv = new BackgroundEventLoopPrivate();
priv->thr = NULL;
Expand Down
2 changes: 1 addition & 1 deletion ext/common/EventedClient.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -689,7 +689,7 @@ class EventedClient {
state = EC_DISCONNECTED;
watchReadEvents(false);
watchWriteEvents(false);
fd = -1;
fd.assign(-1, __FILE__, __LINE__);
emitEvent(onDetach);
return oldFd;
}
Expand Down
Loading

8 comments on commit a84b6ae

@opoplawski
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This breaks the ability to compile against a system libev (as in the Fedora package of passenger). Could some more motivation on the changes to libev be given? Perhaps we can get libev to accept them upstream?

@opoplawski
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I brought this up with upstream - they seem skeptical that this kind of logging would be useful as the fds can change - http://lists.schmorp.de/pipermail/libev/2015q2/002526.html

@FooBarWidget
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have posted the motivation to the libev mailing list.

It's true that, in general, the fds can change. But in the specific way we are using libev, the fds don't change.

If upstream doesn't accept the patch, I recommend that you just build against our vendored libev.

@msva
Copy link

@msva msva commented on a84b6ae Jun 18, 2015

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@FooBarWidget but can you just make using of that ev-related modifications optional (to keep ability to build against system libev anyway)?

As I read your post in libev maillist, you're doing that in debug purposes, but in non-debug cases, I'd bet, it is unneeded to force user to compile against bundled libev every time, isn't it?

@FooBarWidget
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, sorry, I will not do that. Removing the debugging feature severely restricts our ability to troubleshoot unanticipated issues. Everything is fine when there are no issues, but when there are issues, we can't just tell users "yeah, recompile Passenger against our forked libev so that we can figure out what's going on". I do not consider the ability to build against upstream libev to be a strong enough case to remove the debugging features.

@msva
Copy link

@msva msva commented on a84b6ae Jun 19, 2015

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actually, I mean the opposite thing:
I don't say you should not build against patched libev at all. I mean that you can (just as you doing it now) by default compile against bundled libev/libuv. But when user explicitly set USE_VENDORED_LIBEV=no — then it would be nice to not call patched debug-only ev_fd_stuff in the code (so I actually mean «just add few #ifdef's please»).

The issue, for now, is in that fact, that even if user do USE_VENDORED_LIBEV=no USE_VENDORED_LIBUV=no, and he fully understands and takes responsibility about missing debug features, he still unable to compile against system libev 😞

@FooBarWidget
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay, that sounds fair. I've opened a ticket.

@msva
Copy link

@msva msva commented on a84b6ae Jun 19, 2015

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks ;)

Please sign in to comment.