From d960e981029b2819255440e30af470d9cdde875f Mon Sep 17 00:00:00 2001 From: Martin Michelsen Date: Sat, 9 Apr 2022 21:51:16 -0700 Subject: [PATCH] use PrefixedLogger in more places --- src/IPStackSimulator.cc | 71 +++++++++++++++++++++-------------------- src/IPStackSimulator.hh | 1 + src/ProxyServer.cc | 33 +++++++++++-------- src/ProxyServer.hh | 3 ++ src/Server.cc | 32 +++++++++++-------- src/Server.hh | 1 + 6 files changed, 78 insertions(+), 63 deletions(-) diff --git a/src/IPStackSimulator.cc b/src/IPStackSimulator.cc index 440c16b1..46156f5d 100644 --- a/src/IPStackSimulator.cc +++ b/src/IPStackSimulator.cc @@ -27,6 +27,7 @@ using namespace std; static const size_t DEFAULT_RESEND_PUSH_USECS = 200000; // 200ms +PrefixedLogger IPStackSimulator::log("[IPStackSimulator] "); @@ -162,7 +163,7 @@ void IPStackSimulator::dispatch_on_listen_accept( void IPStackSimulator::on_listen_accept(struct evconnlistener* listener, evutil_socket_t fd, struct sockaddr*, int) { int listen_fd = evconnlistener_get_fd(listener); - log(INFO, "[IPStackSimulator] Client fd %d connected via fd %d", + this->log(INFO, "Client fd %d connected via fd %d", fd, listen_fd); struct bufferevent *bev = bufferevent_socket_new(this->base.get(), fd, @@ -183,7 +184,7 @@ void IPStackSimulator::dispatch_on_listen_error( void IPStackSimulator::on_listen_error(struct evconnlistener* listener) { int err = EVUTIL_SOCKET_ERROR(); - log(ERROR, "[IPStackSimulator] Failure on listening socket %d: %d (%s)", + this->log(ERROR, "Failure on listening socket %d: %d (%s)", evconnlistener_get_fd(listener), err, evutil_socket_error_to_string(err)); event_base_loopexit(this->base.get(), nullptr); } @@ -203,7 +204,7 @@ void IPStackSimulator::on_client_input(struct bufferevent* bev) { c = this->bev_to_client.at(bev); } catch (const out_of_range&) { size_t bytes = evbuffer_get_length(buf); - log(ERROR, "[IPStackSimulator] Ignoring data received from unregistered client (0x%zX bytes)", + this->log(ERROR, "Ignoring data received from unregistered client (0x%zX bytes)", bytes); evbuffer_drain(buf, bytes); return; @@ -224,7 +225,7 @@ void IPStackSimulator::on_client_input(struct bufferevent* bev) { this->on_client_frame(c, frame); } catch (const exception& e) { if (this->state->ip_stack_debug) { - log(WARNING, "[IPStackSimulator] Failed to process client frame: %s", e.what()); + this->log(WARNING, "Failed to process client frame: %s", e.what()); print_data(stderr, frame); } } @@ -239,11 +240,11 @@ void IPStackSimulator::on_client_error(struct bufferevent* bev, short events) { if (events & BEV_EVENT_ERROR) { int err = EVUTIL_SOCKET_ERROR(); - log(WARNING, "[IPStackSimulator] Client caused error %d (%s)", err, + this->log(WARNING, "Client caused error %d (%s)", err, evutil_socket_error_to_string(err)); } if (events & (BEV_EVENT_EOF | BEV_EVENT_ERROR)) { - log(INFO, "[IPStackSimulator] Client fd %d disconnected", + this->log(INFO, "Client fd %d disconnected", bufferevent_getfd(bev)); this->bev_to_client.erase(bev); @@ -256,7 +257,7 @@ void IPStackSimulator::on_client_frame( shared_ptr c, const string& frame) { if (this->state->ip_stack_debug) { fputc('\n', stderr); - log(INFO, "[IPStackSimulator] Client sent frame"); + this->log(INFO, "Client sent frame"); print_data(stderr, frame); } this->log_frame(frame); @@ -264,7 +265,7 @@ void IPStackSimulator::on_client_frame( FrameInfo fi(frame); if (this->state->ip_stack_debug) { string fi_header = fi.header_str(); - log(INFO, "[IPStackSimulator] Frame header: %s", fi_header.c_str()); + this->log(INFO, "Frame header: %s", fi_header.c_str()); } if (fi.arp) { @@ -373,7 +374,7 @@ void IPStackSimulator::on_client_arp_frame( evbuffer_add(out_buf, r_payload, sizeof(r_payload)); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Sending ARP response"); + this->log(INFO, "Sending ARP response"); } if (this->pcap_text_log_file) { @@ -435,7 +436,7 @@ void IPStackSimulator::on_client_udp_frame( if (this->state->ip_stack_debug) { string remote_str = this->str_for_ipv4_netloc(fi.ipv4->src_addr, fi.udp->src_port); - log(INFO, "[IPStackSimulator] Sending DNS response to %s", remote_str.c_str()); + this->log(INFO, "Sending DNS response to %s", remote_str.c_str()); } uint16_t frame_size = sizeof(r_ether) + sizeof(r_ipv4) + sizeof(r_udp) + r_data.size(); @@ -482,7 +483,7 @@ uint64_t IPStackSimulator::tcp_conn_key_for_client_frame(const FrameInfo& fi) { void IPStackSimulator::on_client_tcp_frame( shared_ptr c, const FrameInfo& fi) { if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Client sent TCP frame (seq=%08" PRIX32 ", ack=%08" PRIX32 ")", + this->log(INFO, "Client sent TCP frame (seq=%08" PRIX32 ", ack=%08" PRIX32 ")", fi.tcp->seq_num.load(), fi.tcp->ack_num.load()); } @@ -562,10 +563,10 @@ void IPStackSimulator::on_client_tcp_frame( conn_str = this->str_for_tcp_connection(c, conn); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Client opened TCP connection %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ")", + this->log(INFO, "Client opened TCP connection %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ")", conn_str.c_str(), conn.acked_server_seq, conn.next_client_seq); } else { - log(INFO, "[IPStackSimulator] Client opened TCP connection %s", + this->log(INFO, "Client opened TCP connection %s", conn_str.c_str()); } @@ -578,7 +579,7 @@ void IPStackSimulator::on_client_tcp_frame( // they're correct conn_str = this->str_for_tcp_connection(c, conn); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Client resent SYN for TCP connection %s", + this->log(INFO, "Client resent SYN for TCP connection %s", conn_str.c_str()); } } @@ -586,7 +587,7 @@ void IPStackSimulator::on_client_tcp_frame( // Send a SYN+ACK (send_tcp_frame always adds the ACK flag) this->send_tcp_frame(c, conn, TCPHeader::Flag::SYN); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Sent SYN+ACK on %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ")", + this->log(INFO, "Sent SYN+ACK on %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ")", conn_str.c_str(), conn.acked_server_seq, conn.next_client_seq); } @@ -603,7 +604,7 @@ void IPStackSimulator::on_client_tcp_frame( if (fi.tcp->flags & TCPHeader::Flag::ACK) { if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Client sent ACK %08" PRIX32, fi.tcp->ack_num.load()); + this->log(INFO, "Client sent ACK %08" PRIX32, fi.tcp->ack_num.load()); } if (conn->awaiting_first_ack) { if (fi.tcp->ack_num != conn->acked_server_seq + 1) { @@ -615,7 +616,7 @@ void IPStackSimulator::on_client_tcp_frame( } else { if (seq_num_greater(fi.tcp->ack_num, conn->acked_server_seq)) { if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Advancing acked_server_seq from %08" PRIX32, conn->acked_server_seq); + this->log(INFO, "Advancing acked_server_seq from %08" PRIX32, conn->acked_server_seq); } uint32_t ack_delta = fi.tcp->ack_num - conn->acked_server_seq; size_t pending_bytes = evbuffer_get_length(conn->pending_data.get()); @@ -628,7 +629,7 @@ void IPStackSimulator::on_client_tcp_frame( conn->resend_push_usecs = DEFAULT_RESEND_PUSH_USECS; if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Removed %08" PRIX32 " bytes from pending buffer and advanced acked_server_seq to %08" PRIX32, + this->log(INFO, "Removed %08" PRIX32 " bytes from pending buffer and advanced acked_server_seq to %08" PRIX32, ack_delta, conn->acked_server_seq); } @@ -649,7 +650,7 @@ void IPStackSimulator::on_client_tcp_frame( } string conn_str = this->str_for_tcp_connection(c, *conn); - log(INFO, "[IPStackSimulator] Client closed TCP connection %s", conn_str.c_str()); + this->log(INFO, "Client closed TCP connection %s", conn_str.c_str()); // TODO: Are we supposed to send a response to an RST? Here we do, and the // client probably just ignores it anyway @@ -690,8 +691,8 @@ void IPStackSimulator::on_client_tcp_frame( // ignore it (but warn) and send an ACK later, and the client should // retransmit the lost data if (this->state->ip_stack_debug) { - log(WARNING, - "[IPStackSimulator] Client sent out-of-order sequence number (expected %08" PRIX32 ", received %08" PRIX32 ", 0x%zX data bytes)", + this->log(WARNING, + "Client sent out-of-order sequence number (expected %08" PRIX32 ", received %08" PRIX32 ", 0x%zX data bytes)", conn->next_client_seq, fi.tcp->seq_num.load(), fi.payload_size); } payload_skip_bytes = fi.payload_size; @@ -707,10 +708,10 @@ void IPStackSimulator::on_client_tcp_frame( if (this->state->ip_stack_debug) { if (payload_skip_bytes) { - log(INFO, "[IPStackSimulator] Client sent data on TCP connection %s, overlapping existing ack'ed data (0x%zX bytes ignored)", + this->log(INFO, "Client sent data on TCP connection %s, overlapping existing ack'ed data (0x%zX bytes ignored)", conn_str.c_str(), payload_skip_bytes); } else { - log(INFO, "[IPStackSimulator] Client sent data on TCP connection %s", + this->log(INFO, "Client sent data on TCP connection %s", conn_str.c_str()); } print_data(stderr, payload, payload_size); @@ -729,7 +730,7 @@ void IPStackSimulator::on_client_tcp_frame( // Send an ACK this->send_tcp_frame(c, *conn); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Sent PSH ACK on %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ", bytes_received=0x%zX)", + this->log(INFO, "Sent PSH ACK on %s (acked_server_seq=%08" PRIX32 ", next_client_seq=%08" PRIX32 ", bytes_received=0x%zX)", conn_str.c_str(), conn->acked_server_seq, conn->next_client_seq, conn->bytes_received); } } @@ -770,21 +771,21 @@ void IPStackSimulator::open_server_connection( string conn_str = this->str_for_tcp_connection(c, conn); if (port_config->behavior == ServerBehavior::PROXY_SERVER) { if (!this->state->proxy_server.get()) { - log(ERROR, "[IPStackSimulator] TCP connection %s is to non-running proxy server", + this->log(ERROR, "TCP connection %s is to non-running proxy server", conn_str.c_str()); flush_and_free_bufferevent(bevs[1]); } else { this->state->proxy_server->connect_client(bevs[1], conn.server_port); - log(INFO, "[IPStackSimulator] Connected TCP connection %s to proxy server", + this->log(INFO, "Connected TCP connection %s to proxy server", conn_str.c_str()); } } else if (this->game_server.get()) { this->game_server->connect_client(bevs[1], c->ipv4_addr, conn.client_port, port_config->version, port_config->behavior); - log(INFO, "[IPStackSimulator] Connected TCP connection %s to game server", + this->log(INFO, "Connected TCP connection %s to game server", conn_str.c_str()); } else { - log(ERROR, "[IPStackSimulator] No server available for TCP connection %s", + this->log(ERROR, "No server available for TCP connection %s", conn_str.c_str()); flush_and_free_bufferevent(bevs[1]); } @@ -800,7 +801,7 @@ void IPStackSimulator::send_pending_push_frame( size_t bytes_to_send = min(pending_bytes, conn.max_frame_size); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Sending PSH frame with seq_num %08" PRIX32 ", 0x%zX/0x%zX data bytes", + this->log(INFO, "Sending PSH frame with seq_num %08" PRIX32 ", 0x%zX/0x%zX data bytes", conn.acked_server_seq, bytes_to_send, pending_bytes); } @@ -888,7 +889,7 @@ void IPStackSimulator::dispatch_on_resend_push(evutil_socket_t, short, void* ctx auto* conn = reinterpret_cast(ctx); auto c = conn->client.lock(); if (!c.get()) { - log(WARNING, "[IPStackSimulator] Resend push event triggered for deleted client; ignoring"); + IPStackSimulator::log(WARNING, "Resend push event triggered for deleted client; ignoring"); } else { c->sim->on_resend_push(c, *conn); } @@ -902,7 +903,7 @@ void IPStackSimulator::dispatch_on_server_input(struct bufferevent*, void* ctx) auto* conn = reinterpret_cast(ctx); auto c = conn->client.lock(); if (!c.get()) { - log(WARNING, "[IPStackSimulator] Server input event triggered for deleted client; ignoring"); + IPStackSimulator::log(WARNING, "Server input event triggered for deleted client; ignoring"); } else { c->sim->on_server_input(c, *conn); } @@ -911,7 +912,7 @@ void IPStackSimulator::dispatch_on_server_input(struct bufferevent*, void* ctx) void IPStackSimulator::on_server_input(shared_ptr c, IPClient::TCPConnection& conn) { struct evbuffer* buf = bufferevent_get_input(conn.server_bev.get()); if (this->state->ip_stack_debug) { - log(INFO, "[IPStackSimulator] Server input event: 0x%zX bytes to read", + this->log(INFO, "Server input event: 0x%zX bytes to read", evbuffer_get_length(buf)); } @@ -924,7 +925,7 @@ void IPStackSimulator::dispatch_on_server_error( auto* conn = reinterpret_cast(ctx); auto c = conn->client.lock(); if (!c.get()) { - log(WARNING, "[IPStackSimulator] Server error event triggered for deleted client; ignoring"); + IPStackSimulator::log(WARNING, "Server error event triggered for deleted client; ignoring"); } else { c->sim->on_server_error(c, *conn, events); } @@ -934,7 +935,7 @@ void IPStackSimulator::on_server_error( shared_ptr c, IPClient::TCPConnection& conn, short events) { if (events & BEV_EVENT_ERROR) { int err = EVUTIL_SOCKET_ERROR(); - log(WARNING, "[IPStackSimulator] Received error %d from virtual connection (%s)", err, + this->log(WARNING, "Received error %d from virtual connection (%s)", err, evutil_socket_error_to_string(err)); } if (events & (BEV_EVENT_EOF | BEV_EVENT_ERROR)) { @@ -946,7 +947,7 @@ void IPStackSimulator::on_server_error( // Delete the connection object (this also flushes and frees the server // virtual connection bufferevent) string conn_str = this->str_for_tcp_connection(c, conn); - log(INFO, "[IPStackSimulator] Server closed TCP connection %s", + this->log(INFO, "Server closed TCP connection %s", conn_str.c_str()); c->tcp_connections.erase(this->tcp_conn_key_for_connection(conn)); } diff --git a/src/IPStackSimulator.hh b/src/IPStackSimulator.hh index bbda1456..b02cf42a 100644 --- a/src/IPStackSimulator.hh +++ b/src/IPStackSimulator.hh @@ -29,6 +29,7 @@ public: static uint32_t connect_address_for_remote_address(uint32_t remote_addr); private: + static PrefixedLogger log; std::shared_ptr base; std::shared_ptr game_server; std::shared_ptr state; diff --git a/src/ProxyServer.cc b/src/ProxyServer.cc index bedd8208..49b40c45 100644 --- a/src/ProxyServer.cc +++ b/src/ProxyServer.cc @@ -46,7 +46,8 @@ static void flush_and_free_bufferevent(struct bufferevent* bev) { ProxyServer::ProxyServer( shared_ptr base, shared_ptr state) - : base(base), + : log("[ProxyServer] "), + base(base), state(state), next_unlicensed_session_id(0xFF00000000000001) { } @@ -55,8 +56,6 @@ void ProxyServer::listen(uint16_t port, GameVersion version, shared_ptr socket_obj(new ListeningSocket( this, port, version, default_destination)); auto l = this->listeners.emplace(port, socket_obj).first->second; - log(INFO, "[ProxyServer] Listening on TCP port %hu (%s) on fd %d", - port, name_for_version(version), static_cast(l->fd)); } ProxyServer::ListeningSocket::ListeningSocket( @@ -65,6 +64,7 @@ ProxyServer::ListeningSocket::ListeningSocket( GameVersion version, const struct sockaddr_storage* default_destination) : server(server), + log(string_printf("[ProxyServer:ListeningSocket:%hu] ", port)), port(port), fd(::listen("", port, SOMAXCONN)), listener(nullptr, evconnlistener_free), @@ -90,6 +90,9 @@ ProxyServer::ListeningSocket::ListeningSocket( } else { this->default_destination.ss_family = 0; } + + this->log(INFO, "Listening on TCP port %hu (%s) on fd %d", + this->port, name_for_version(this->version), static_cast(this->fd)); } void ProxyServer::ListeningSocket::dispatch_on_listen_accept( @@ -103,7 +106,7 @@ void ProxyServer::ListeningSocket::dispatch_on_listen_error( } void ProxyServer::ListeningSocket::on_listen_accept(int fd) { - log(INFO, "[ProxyServer] Client connected on fd %d", fd); + this->log(INFO, "Client connected on fd %d", fd); auto* bev = bufferevent_socket_new(this->server->base.get(), fd, BEV_OPT_CLOSE_ON_FREE | BEV_OPT_DEFER_CALLBACKS); this->server->on_client_connect(bev, this->port, this->version, @@ -112,7 +115,7 @@ void ProxyServer::ListeningSocket::on_listen_accept(int fd) { void ProxyServer::ListeningSocket::on_listen_error() { int err = EVUTIL_SOCKET_ERROR(); - log(ERROR, "[ProxyServer] Failure on listening socket %d: %d (%s)", + this->log(ERROR, "Failure on listening socket %d: %d (%s)", evconnlistener_get_fd(this->listener.get()), err, evutil_socket_error_to_string(err)); event_base_loopexit(this->server->base.get(), nullptr); @@ -127,13 +130,13 @@ void ProxyServer::connect_client(struct bufferevent* bev, uint16_t server_port) try { version = this->listeners.at(server_port)->version; } catch (const out_of_range&) { - log(INFO, "[ProxyServer] Virtual connection received on unregistered port %hu; closing it", + this->log(INFO, "Virtual connection received on unregistered port %hu; closing it", server_port); flush_and_free_bufferevent(bev); return; } - log(INFO, "[ProxyServer] Client connected on virtual connection %p", bev); + this->log(INFO, "Client connected on virtual connection %p", bev); this->on_client_connect(bev, server_port, version, nullptr); } @@ -171,7 +174,7 @@ void ProxyServer::on_client_connect( throw logic_error("stale unlinked session exists"); } auto session = emplace_ret.first->second; - log(INFO, "[ProxyServer] Opened unlinked session"); + this->log(INFO, "Opened unlinked session"); switch (version) { case GameVersion::PATCH: @@ -212,6 +215,7 @@ void ProxyServer::on_client_connect( ProxyServer::UnlinkedSession::UnlinkedSession( ProxyServer* server, struct bufferevent* bev, uint16_t local_port, GameVersion version) : server(server), + log(string_printf("[ProxyServer:UnlinkedSession:%p] ", bev)), bev(bev, flush_and_free_bufferevent), local_port(local_port), version(version) { @@ -275,7 +279,7 @@ void ProxyServer::UnlinkedSession::on_client_input() { }); } catch (const exception& e) { - log(ERROR, "[ProxyServer] Failed to process command from unlinked client: %s", e.what()); + this->log(ERROR, "Failed to process command from unlinked client: %s", e.what()); should_close_unlinked_session = true; } @@ -299,7 +303,7 @@ void ProxyServer::UnlinkedSession::on_client_input() { // destination in the client config. If there is, open a new linked // session and set its initial destination if (client_config.magic != CLIENT_CONFIG_MAGIC) { - log(ERROR, "[ProxyServer] Client configuration is invalid; cannot open session"); + this->log(ERROR, "Client configuration is invalid; cannot open session"); } else { session.reset(new LinkedSession( this->server, @@ -327,6 +331,7 @@ void ProxyServer::UnlinkedSession::on_client_input() { } if (should_close_unlinked_session) { + this->log(INFO, "Closing session"); this->server->bev_to_unlinked_session.erase(session_key); // At this point, (*this) is destroyed! We must be careful not to touch it. } @@ -335,11 +340,11 @@ void ProxyServer::UnlinkedSession::on_client_input() { void ProxyServer::UnlinkedSession::on_client_error(short events) { if (events & BEV_EVENT_ERROR) { int err = EVUTIL_SOCKET_ERROR(); - log(WARNING, "[ProxyServer] Error %d (%s) in unlinked client stream", err, + this->log(WARNING, "Error %d (%s) in unlinked client stream", err, evutil_socket_error_to_string(err)); } if (events & (BEV_EVENT_ERROR | BEV_EVENT_EOF)) { - log(WARNING, "[ProxyServer] Unlinked client has disconnected"); + this->log(WARNING, "Unlinked client has disconnected"); this->server->bev_to_unlinked_session.erase(this->bev.get()); } } @@ -355,7 +360,7 @@ ProxyServer::LinkedSession::LinkedSession( id(id), client_name(string_printf("LinkedSession:%08" PRIX64 ":client", this->id)), server_name(string_printf("LinkedSession:%08" PRIX64 ":server", this->id)), - log(string_printf("[LinkedSession:%08" PRIX64 "] ", this->id)), + log(string_printf("[ProxyServer:LinkedSession:%08" PRIX64 "] ", this->id)), timeout_event(event_new(this->server->base.get(), -1, EV_TIMEOUT, &LinkedSession::dispatch_on_timeout, this), event_free), license(nullptr), @@ -672,6 +677,6 @@ std::shared_ptr ProxyServer::create_licensed_session void ProxyServer::delete_session(uint64_t id) { if (this->id_to_session.erase(id)) { - log(INFO, "Closed LinkedSession:%08" PRIX64, id); + this->log(INFO, "Closed LinkedSession:%08" PRIX64, id); } } diff --git a/src/ProxyServer.hh b/src/ProxyServer.hh index 27d92342..2a968e87 100644 --- a/src/ProxyServer.hh +++ b/src/ProxyServer.hh @@ -154,6 +154,7 @@ private: struct ListeningSocket { ProxyServer* server; + PrefixedLogger log; uint16_t port; scoped_fd fd; std::unique_ptr listener; @@ -176,6 +177,7 @@ private: struct UnlinkedSession { ProxyServer* server; + PrefixedLogger log; std::unique_ptr bev; uint16_t local_port; GameVersion version; @@ -194,6 +196,7 @@ private: void on_client_error(short events); }; + PrefixedLogger log; std::shared_ptr base; std::shared_ptr state; std::map> listeners; diff --git a/src/Server.cc b/src/Server.cc index 6f2e6c9a..c939a624 100644 --- a/src/Server.cc +++ b/src/Server.cc @@ -38,9 +38,9 @@ void Server::disconnect_client(shared_ptr c) { int fd = bufferevent_getfd(bev); if (fd < 0) { - log(INFO, "[Server] Client on virtual connection %p disconnected", bev); + this->log(INFO, "[Server] Client on virtual connection %p disconnected", bev); } else { - log(INFO, "[Server] Client on fd %d disconnected", fd); + this->log(INFO, "[Server] Client on fd %d disconnected", fd); } // if the output buffer is not empty, move the client into the draining pool @@ -100,13 +100,13 @@ void Server::on_listen_accept(struct evconnlistener* listener, try { listening_socket = &this->listening_sockets.at(listen_fd); } catch (const out_of_range& e) { - log(WARNING, "[Server] Can\'t determine version for socket %d; disconnecting client", + this->log(WARNING, "Can\'t determine version for socket %d; disconnecting client", listen_fd); close(fd); return; } - log(INFO, "[Server] Client fd %d connected via fd %d", fd, listen_fd); + this->log(INFO, "Client fd %d connected via fd %d", fd, listen_fd); struct bufferevent *bev = bufferevent_socket_new(this->base.get(), fd, BEV_OPT_CLOSE_ON_FREE | BEV_OPT_DEFER_CALLBACKS); @@ -124,7 +124,7 @@ void Server::on_listen_accept(struct evconnlistener* listener, void Server::connect_client( struct bufferevent* bev, uint32_t address, uint16_t port, GameVersion version, ServerBehavior initial_state) { - log(INFO, "[Server] Client connected on virtual connection %p", bev); + this->log(INFO, "Client connected on virtual connection %p", bev); shared_ptr c(new Client(bev, version, initial_state)); this->bev_to_client.emplace(make_pair(bev, c)); @@ -145,7 +145,7 @@ void Server::connect_client( void Server::on_listen_error(struct evconnlistener* listener) { int err = EVUTIL_SOCKET_ERROR(); - log(ERROR, "[Server] Failure on listening socket %d: %d (%s)", + this->log(ERROR, "Failure on listening socket %d: %d (%s)", evconnlistener_get_fd(listener), err, evutil_socket_error_to_string(err)); event_base_loopexit(this->base.get(), nullptr); } @@ -155,7 +155,7 @@ void Server::on_client_input(struct bufferevent* bev) { try { c = this->bev_to_client.at(bev); } catch (const out_of_range& e) { - log(WARNING, "[Server] Received message from client with no configuration"); + this->log(WARNING, "Received message from client with no configuration"); // ignore all the data // TODO: we probably should disconnect them or something @@ -186,7 +186,7 @@ void Server::on_disconnecting_client_output(struct bufferevent* bev) { void Server::on_client_error(struct bufferevent* bev, short events) { if (events & BEV_EVENT_ERROR) { int err = EVUTIL_SOCKET_ERROR(); - log(WARNING, "[Server] Client caused error %d (%s)", err, + this->log(WARNING, "Client caused error %d (%s)", err, evutil_socket_error_to_string(err)); } if (events & (BEV_EVENT_EOF | BEV_EVENT_ERROR)) { @@ -198,7 +198,7 @@ void Server::on_disconnecting_client_error(struct bufferevent* bev, short events) { if (events & BEV_EVENT_ERROR) { int err = EVUTIL_SOCKET_ERROR(); - log(WARNING, "[Server] Disconnecting client caused error %d (%s)", err, + this->log(WARNING, "Disconnecting client caused error %d (%s)", err, evutil_socket_error_to_string(err)); } if (events & (BEV_EVENT_EOF | BEV_EVENT_ERROR)) { @@ -213,20 +213,24 @@ void Server::receive_and_process_commands(shared_ptr c) { try { process_command(this->state, c, command, flag, data); } catch (const exception& e) { - log(INFO, "[Server] Error in client stream: %s", e.what()); + this->log(INFO, "Error in client stream: %s", e.what()); c->should_disconnect = true; return; } }); } -Server::Server(shared_ptr base, - shared_ptr state) : base(base), state(state) { } +Server::Server( + shared_ptr base, + shared_ptr state) + : log("[Server] "), + base(base), + state(state) { } void Server::listen(const string& socket_path, GameVersion version, ServerBehavior behavior) { int fd = ::listen(socket_path, 0, SOMAXCONN); - log(INFO, "[Server] Listening on Unix socket %s (%s) on fd %d", + this->log(INFO, "Listening on Unix socket %s (%s) on fd %d", socket_path.c_str(), name_for_version(version), fd); this->add_socket(fd, version, behavior); } @@ -235,7 +239,7 @@ void Server::listen(const string& addr, int port, GameVersion version, ServerBehavior behavior) { int fd = ::listen(addr, port, SOMAXCONN); string netloc_str = render_netloc(addr, port); - log(INFO, "[Server] Listening on TCP interface %s (%s) on fd %d", + this->log(INFO, "Listening on TCP interface %s (%s) on fd %d", netloc_str.c_str(), name_for_version(version), fd); this->add_socket(fd, version, behavior); } diff --git a/src/Server.hh b/src/Server.hh index fc96f4d9..1dc699b8 100644 --- a/src/Server.hh +++ b/src/Server.hh @@ -30,6 +30,7 @@ public: GameVersion version, ServerBehavior initial_state); private: + PrefixedLogger log; std::shared_ptr base; struct ListeningSocket {