0
0
Fork 0
mirror of https://github.com/matrix-construct/construct synced 2024-11-29 18:22:50 +01:00

ircd: Towards debug message uniformity.

This commit is contained in:
Jason Volk 2018-01-11 18:48:00 -08:00
parent d151d96d83
commit 4d310ac22b
3 changed files with 62 additions and 51 deletions

View file

@ -199,10 +199,6 @@ ircd::add_client(std::shared_ptr<socket> s)
make_client(std::move(s)) make_client(std::move(s))
}; };
log::debug("client[%s] CONNECTED local[%s]",
string(remote(*client)),
string(local(*client)));
async_recv_next(client, async_timeout); async_recv_next(client, async_timeout);
return client; return client;
} }
@ -404,7 +400,9 @@ bool
ircd::handle_ec_eof(client &client) ircd::handle_ec_eof(client &client)
try try
{ {
log::debug("client[%s]: EOF", log::debug("socket(%p) local[%s] remote[%s] end of file",
client.sock.get(),
string(local(client)),
string(remote(client))); string(remote(client)));
close(client, net::dc::SSL_NOTIFY, net::close_ignore); close(client, net::dc::SSL_NOTIFY, net::close_ignore);
@ -412,8 +410,8 @@ try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log::error("client(%p): EOF: %s", log::error("socket(%p) EOF: %s",
&client, client.sock.get(),
e.what()); e.what());
return false; return false;
@ -426,7 +424,9 @@ bool
ircd::handle_ec_short_read(client &client) ircd::handle_ec_short_read(client &client)
try try
{ {
log::warning("client[%s]: short_read", log::warning("socket(%p) local[%s] remote[%s] short_read",
client.sock.get(),
string(local(client)),
string(remote(client))); string(remote(client)));
close(client, net::dc::RST, net::close_ignore); close(client, net::dc::RST, net::close_ignore);
@ -434,8 +434,8 @@ try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log::error("client(%p): short_read: %s", log::error("socket(%p) short_read: %s",
&client, client.sock.get(),
e.what()); e.what());
return false; return false;
@ -450,7 +450,9 @@ ircd::handle_ec_timeout(client &client)
try try
{ {
assert(bool(client.sock)); assert(bool(client.sock));
log::warning("client[%s]: disconnecting after inactivity timeout", log::warning("socket(%p) local[%s] remote[%s] disconnecting after inactivity timeout",
client.sock.get(),
string(local(client)),
string(remote(client))); string(remote(client)));
close(client, net::dc::SSL_NOTIFY, net::close_ignore); close(client, net::dc::SSL_NOTIFY, net::close_ignore);
@ -458,8 +460,8 @@ try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log::error("client(%p): timeout: %s", log::error("socket(%p) timeout: %s",
&client, client.sock.get(),
e.what()); e.what());
return false; return false;
@ -471,8 +473,9 @@ bool
ircd::handle_ec_default(client &client, ircd::handle_ec_default(client &client,
const error_code &ec) const error_code &ec)
{ {
log::warning("client(%p)[%s]: %s", log::warning("socket(%p) local[%s] remote[%s] %s",
&client, client.sock.get(),
string(local(client)),
string(remote(client)), string(remote(client)),
string(ec)); string(ec));
@ -512,7 +515,10 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log::critical("~client(%p): %s", this, e.what()); log::critical("socket(%p) ~client(%p): %s",
sock.get(),
this,
e.what());
return; return;
} }
@ -600,8 +606,10 @@ catch(const boost::system::system_error &e)
using boost::asio::error::get_ssl_category; using boost::asio::error::get_ssl_category;
using boost::asio::error::get_misc_category; using boost::asio::error::get_misc_category;
log::debug("client(%p): handle error: %s", log::debug("socket(%p) local[%s] remote[%s] error during request: %s",
(const void *)this, sock.get(),
string(local(*this)),
string(remote(*this)),
string(e.code())); string(e.code()));
const error_code &ec{e.code()}; const error_code &ec{e.code()};
@ -651,11 +659,11 @@ catch(const boost::system::system_error &e)
break; break;
} }
log::error("client(%p): (unexpected) %s: (%d) %s", log::error("socket(%p) (unexpected) %s: (%d) %s",
(const void *)this, sock.get(),
ec.category().name(), ec.category().name(),
value, value,
ec.message()); ec.message());
close(*this, net::dc::RST, net::close_ignore); close(*this, net::dc::RST, net::close_ignore);
return false; return false;

View file

@ -795,7 +795,7 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.error("acceptor(%p): join: %s", log.error("acceptor(%p) join: %s",
this, this,
e.what()); e.what());
} }
@ -810,7 +810,7 @@ noexcept try
} }
catch(const boost::system::system_error &e) catch(const boost::system::system_error &e)
{ {
log.error("acceptor(%p): interrupt: %s", log.error("acceptor(%p) interrupt: %s",
this, this,
string(e)); string(e));
@ -1053,7 +1053,7 @@ catch(const ctx::interrupted &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.error("%s: socket(%p): in handshake(): %s", log.error("%s: socket(%p) in handshake(): %s",
std::string(*this), std::string(*this),
sock.get(), sock.get(),
e.what()); e.what());
@ -1248,7 +1248,7 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): close: %s", this, e.what()); log.critical("socket(%p) close: %s", this, e.what());
return; return;
} }
@ -1257,7 +1257,7 @@ ircd::net::socket::connect(const endpoint &ep,
const open_opts &opts, const open_opts &opts,
eptr_handler callback) eptr_handler callback)
{ {
log.debug("socket(%p) attempting connect to remote: %s for the next %ld$ms", log.debug("socket(%p) attempting connect remote[%s] to:%ld$ms",
this, this,
string(ep), string(ep),
opts.connect_timeout.count()); opts.connect_timeout.count());
@ -1267,17 +1267,18 @@ ircd::net::socket::connect(const endpoint &ep,
std::bind(&socket::handle_connect, this, weak_from(*this), opts, std::move(callback), ph::_1) std::bind(&socket::handle_connect, this, weak_from(*this), opts, std::move(callback), ph::_1)
}; };
sd.async_connect(ep, std::move(connect_handler));
set_timeout(opts.connect_timeout); set_timeout(opts.connect_timeout);
sd.async_connect(ep, std::move(connect_handler));
} }
void void
ircd::net::socket::handshake(const open_opts &opts, ircd::net::socket::handshake(const open_opts &opts,
eptr_handler callback) eptr_handler callback)
{ {
log.debug("socket(%p) performing handshake with %s for '%s' for the next %ld$ms", log.debug("socket(%p) local[%s] remote[%s] handshaking for '%s' to:%ld$ms",
this, this,
string(remote()), string(local_ipport(*this)),
string(remote_ipport(*this)),
common_name(opts), common_name(opts),
opts.handshake_timeout.count()); opts.handshake_timeout.count());
@ -1358,7 +1359,7 @@ catch(const boost::system::system_error &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): disconnect: type: %d: %s", log.critical("socket(%p) disconnect: type: %d: %s",
(const void *)this, (const void *)this,
uint(opts.type), uint(opts.type),
e.what()); e.what());
@ -1511,7 +1512,7 @@ noexcept try
} }
catch(const boost::system::system_error &e) catch(const boost::system::system_error &e)
{ {
log.error("socket(%p): handle: %s", log.error("socket(%p) handle: %s",
this, this,
e.what()); e.what());
@ -1523,7 +1524,7 @@ catch(const std::bad_weak_ptr &e)
// This handler may still be registered with asio after the socket destructs, so // This handler may still be registered with asio after the socket destructs, so
// the weak_ptr will indicate that fact. However, this is never intended and is // the weak_ptr will indicate that fact. However, this is never intended and is
// a debug assertion which should be corrected. // a debug assertion which should be corrected.
log.warning("socket(%p): belated callback to handler... (%s)", log.warning("socket(%p) belated callback to handler... (%s)",
this, this,
e.what()); e.what());
@ -1532,7 +1533,7 @@ catch(const std::bad_weak_ptr &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): handle: %s", log.critical("socket(%p) handle: %s",
this, this,
e.what()); e.what());
@ -1573,7 +1574,7 @@ noexcept try
// All other errors are unexpected, logged and ignored here. // All other errors are unexpected, logged and ignored here.
default: default:
{ {
log.critical("socket(%p): handle_timeout: unexpected: %s\n", log.critical("socket(%p) handle_timeout: unexpected: %s\n",
(const void *)this, (const void *)this,
string(ec)); string(ec));
assert(0); assert(0);
@ -1586,7 +1587,7 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): handle timeout: %s", log.critical("socket(%p) handle timeout: %s",
(const void *)this, (const void *)this,
e.what()); e.what());
assert(0); assert(0);
@ -1603,7 +1604,7 @@ noexcept try
{ {
const life_guard<socket> s{wp}; const life_guard<socket> s{wp};
assert(!timedout || ec == boost::system::errc::operation_canceled); assert(!timedout || ec == boost::system::errc::operation_canceled);
log.debug("socket(%p) connect by local: %s: to remote: %s %s", log.debug("socket(%p) local[%s] remote[%s] connect %s",
this, this,
string(local_ipport(*this)), string(local_ipport(*this)),
string(remote_ipport(*this)), string(remote_ipport(*this)),
@ -1633,7 +1634,7 @@ noexcept try
} }
catch(const std::bad_weak_ptr &e) catch(const std::bad_weak_ptr &e)
{ {
log.warning("socket(%p): belated callback to handle_connect... (%s)", log.warning("socket(%p) belated callback to handle_connect... (%s)",
this, this,
e.what()); e.what());
@ -1642,7 +1643,7 @@ catch(const std::bad_weak_ptr &e)
} }
catch(const boost::system::system_error &e) catch(const boost::system::system_error &e)
{ {
log.error("socket(%p): after connect: %s", log.error("socket(%p) after connect: %s",
this, this,
e.what()); e.what());
@ -1651,7 +1652,7 @@ catch(const boost::system::system_error &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): handle_connect: %s", log.critical("socket(%p) handle_connect: %s",
this, this,
e.what()); e.what());
@ -1666,7 +1667,7 @@ ircd::net::socket::handle_disconnect(std::shared_ptr<socket> s,
noexcept try noexcept try
{ {
assert(!timedout || ec == boost::system::errc::operation_canceled); assert(!timedout || ec == boost::system::errc::operation_canceled);
log.debug("socket(%p) disconnect by local: %s from remote: %s: %s", log.debug("socket(%p) local[%s] remote[%s] disconnect %s",
this, this,
string(local_ipport(*this)), string(local_ipport(*this)),
string(remote_ipport(*this)), string(remote_ipport(*this)),
@ -1681,7 +1682,7 @@ noexcept try
} }
catch(const boost::system::system_error &e) catch(const boost::system::system_error &e)
{ {
log.error("socket(%p): disconnect: %s", log.error("socket(%p) disconnect: %s",
this, this,
e.what()); e.what());
@ -1690,7 +1691,7 @@ catch(const boost::system::system_error &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): disconnect: %s", log.critical("socket(%p) disconnect: %s",
this, this,
e.what()); e.what());
@ -1706,7 +1707,7 @@ noexcept try
{ {
const life_guard<socket> s{wp}; const life_guard<socket> s{wp};
assert(!timedout || ec == boost::system::errc::operation_canceled); assert(!timedout || ec == boost::system::errc::operation_canceled);
log.debug("socket(%p) handshake by local: %s to remote: %s: %s", log.debug("socket(%p) local[%s] remote[%s] handshake %s",
this, this,
string(local_ipport(*this)), string(local_ipport(*this)),
string(remote_ipport(*this)), string(remote_ipport(*this)),
@ -1722,7 +1723,7 @@ noexcept try
} }
catch(const boost::system::system_error &e) catch(const boost::system::system_error &e)
{ {
log.error("socket(%p): after handshake: %s", log.error("socket(%p) after handshake: %s",
this, this,
e.what()); e.what());
@ -1731,7 +1732,7 @@ catch(const boost::system::system_error &e)
} }
catch(const std::bad_weak_ptr &e) catch(const std::bad_weak_ptr &e)
{ {
log.warning("socket(%p): belated callback to handle_handshake... (%s)", log.warning("socket(%p) belated callback to handle_handshake... (%s)",
this, this,
e.what()); e.what());
assert(0); assert(0);
@ -1739,7 +1740,7 @@ catch(const std::bad_weak_ptr &e)
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): handle_handshake: %s", log.critical("socket(%p) handle_handshake: %s",
this, this,
e.what()); e.what());
assert(0); assert(0);
@ -1875,7 +1876,7 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): async handler: unhandled exception: %s", log.critical("socket(%p) async handler: unhandled exception: %s",
this, this,
e.what()); e.what());
} }
@ -1889,7 +1890,7 @@ noexcept try
} }
catch(const std::exception &e) catch(const std::exception &e)
{ {
log.critical("socket(%p): async handler: unhandled exception: %s", log.critical("socket(%p) async handler: unhandled exception: %s",
this, this,
e.what()); e.what());
} }

View file

@ -641,7 +641,9 @@ ircd::resource::response::response(client &client,
write_closure(client)(vector); write_closure(client)(vector);
log::debug("client[%s] HTTP %d %s in %ld$us; response in %ld$us (%s) content-length: %zu", log::debug("socket(%p) local[%s] remote[%s] HTTP %d %s in %ld$us; response in %ld$us (%s) content-length:%zu",
client.sock.get(),
string(local(client)),
string(remote(client)), string(remote(client)),
int(code), int(code),
http::status(code), http::status(code),