Stats, stats everywhere (I added a #netstats command)

This commit is contained in:
KimLS 2019-03-09 22:25:04 -08:00
parent 5c32afc77d
commit ee1fcdf5fa
13 changed files with 154 additions and 74 deletions

View File

@ -51,14 +51,8 @@ public:
virtual MatchState CheckSignature(const Signature *sig) { return MatchFailed; }
virtual EQStreamState GetState() = 0;
virtual void SetOpcodeManager(OpcodeManager **opm) = 0;
virtual const uint32 GetBytesSent() const { return 0; }
virtual const uint32 GetBytesRecieved() const { return 0; }
virtual const uint32 GetBytesSentPerSecond() const { return 0; }
virtual const uint32 GetBytesRecvPerSecond() const { return 0; }
virtual const EQEmu::versions::ClientVersion ClientVersion() const { return EQEmu::versions::ClientVersion::Unknown; }
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection() = 0;
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection() const = 0;
};
#endif /*EQSTREAMINTF_H_*/

View File

@ -82,26 +82,6 @@ uint16 EQStreamProxy::GetRemotePort() const {
return(m_stream->GetRemotePort());
}
const uint32 EQStreamProxy::GetBytesSent() const
{
return(m_stream->GetBytesSent());
}
const uint32 EQStreamProxy::GetBytesRecieved() const
{
return(m_stream->GetBytesRecieved());
}
const uint32 EQStreamProxy::GetBytesSentPerSecond() const
{
return(m_stream->GetBytesSentPerSecond());
}
const uint32 EQStreamProxy::GetBytesRecvPerSecond() const
{
return(m_stream->GetBytesRecvPerSecond());
}
void EQStreamProxy::ReleaseFromUse() {
m_stream->ReleaseFromUse();
}
@ -110,7 +90,7 @@ void EQStreamProxy::RemoveData() {
m_stream->RemoveData();
}
std::shared_ptr<EQ::Net::DaybreakConnection> EQStreamProxy::GetRawConnection() {
std::shared_ptr<EQ::Net::DaybreakConnection> EQStreamProxy::GetRawConnection() const {
return m_stream->GetRawConnection();
}

View File

@ -31,13 +31,7 @@ public:
virtual const EQEmu::versions::ClientVersion ClientVersion() const;
virtual EQStreamState GetState();
virtual void SetOpcodeManager(OpcodeManager **opm);
virtual const uint32 GetBytesSent() const;
virtual const uint32 GetBytesRecieved() const;
virtual const uint32 GetBytesSentPerSecond() const;
virtual const uint32 GetBytesRecvPerSecond() const;
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection();
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection() const;
protected:
std::shared_ptr<EQStreamInterface> const m_stream; //we own this stream object.

View File

@ -41,6 +41,7 @@ void EQ::Net::DaybreakConnectionManager::Attach(uv_loop_t *loop)
uv_timer_start(&m_timer, [](uv_timer_t *handle) {
DaybreakConnectionManager *c = (DaybreakConnectionManager*)handle->data;
c->UpdateDataBudget();
c->Process();
c->ProcessResend();
}, update_rate, update_rate);
@ -162,6 +163,25 @@ void EQ::Net::DaybreakConnectionManager::Process()
}
}
void EQ::Net::DaybreakConnectionManager::UpdateDataBudget()
{
auto outgoing_data_rate = m_options.outgoing_data_rate;
if (outgoing_data_rate <= 0.0) {
return;
}
auto update_rate = (uint64_t)(1000.0 / m_options.tic_rate_hertz);
auto budget_add = update_rate * outgoing_data_rate / 1000.0;
auto iter = m_connections.begin();
while (iter != m_connections.end()) {
auto &connection = iter->second;
connection->UpdateDataBudget(budget_add);
iter++;
}
}
void EQ::Net::DaybreakConnectionManager::ProcessResend()
{
auto iter = m_connections.begin();
@ -283,6 +303,7 @@ EQ::Net::DaybreakConnection::DaybreakConnection(DaybreakConnectionManager *owner
m_combined[0] = 0;
m_combined[1] = OP_Combined;
m_last_session_stats = Clock::now();
m_outgoing_budget = owner->m_options.outgoing_data_rate;
}
//new connection made as client
@ -305,6 +326,7 @@ EQ::Net::DaybreakConnection::DaybreakConnection(DaybreakConnectionManager *owner
m_combined[0] = 0;
m_combined[1] = OP_Combined;
m_last_session_stats = Clock::now();
m_outgoing_budget = owner->m_options.outgoing_data_rate;
}
EQ::Net::DaybreakConnection::~DaybreakConnection()
@ -347,6 +369,11 @@ void EQ::Net::DaybreakConnection::QueuePacket(Packet &p, int stream, bool reliab
InternalQueuePacket(p, stream, reliable);
}
EQ::Net::DaybreakConnectionStats EQ::Net::DaybreakConnection::GetStats()
{
return m_stats;
}
void EQ::Net::DaybreakConnection::ResetStats()
{
m_stats = DaybreakConnectionStats();
@ -738,6 +765,10 @@ void EQ::Net::DaybreakConnection::ProcessDecodedPacket(const Packet &p)
case OP_SessionStatRequest:
{
auto request = p.GetSerialize<DaybreakSessionStatRequest>(0);
m_stats.sync_remote_sent_packets = EQ::Net::NetworkToHost(request.packets_sent);
m_stats.sync_remote_recv_packets = EQ::Net::NetworkToHost(request.packets_recv);
m_stats.sync_sent_packets = m_stats.sent_packets;
m_stats.sync_recv_packets = m_stats.recv_packets;
DaybreakSessionStatResponse response;
response.zero = 0;
@ -754,6 +785,12 @@ void EQ::Net::DaybreakConnection::ProcessDecodedPacket(const Packet &p)
break;
}
case OP_SessionStatResponse:
auto response = p.GetSerialize<DaybreakSessionStatResponse>(0);
m_stats.sync_remote_sent_packets = EQ::Net::NetworkToHost(response.server_sent);
m_stats.sync_remote_recv_packets = EQ::Net::NetworkToHost(response.server_recv);
m_stats.sync_sent_packets = m_stats.sent_packets;
m_stats.sync_recv_packets = m_stats.recv_packets;
break;
default:
LogF(Logs::Detail, Logs::Netcode, "Unhandled opcode {0:#x}", p.GetInt8(1));
@ -1024,7 +1061,21 @@ void EQ::Net::DaybreakConnection::ProcessResend(int stream)
auto time_since_last_send = std::chrono::duration_cast<std::chrono::milliseconds>(now - entry.second.last_sent);
if (entry.second.times_resent == 0) {
if ((size_t)time_since_last_send.count() > entry.second.resend_delay) {
InternalBufferedSend(entry.second.packet);
auto &p = entry.second.packet;
if (p.Length() >= DaybreakHeader::size()) {
if (p.GetInt8(0) == 0 && p.GetInt8(1) >= OP_Fragment && p.GetInt8(1) <= OP_Fragment4) {
m_stats.resent_fragments++;
}
else {
m_stats.resent_full++;
}
}
else {
m_stats.resent_full++;
}
m_stats.resent_packets++;
InternalBufferedSend(p);
entry.second.last_sent = now;
entry.second.times_resent++;
entry.second.resend_delay = EQEmu::Clamp(entry.second.resend_delay * 2, m_owner->m_options.resend_delay_min, m_owner->m_options.resend_delay_max);
@ -1039,7 +1090,21 @@ void EQ::Net::DaybreakConnection::ProcessResend(int stream)
}
if ((size_t)time_since_last_send.count() > entry.second.resend_delay) {
InternalBufferedSend(entry.second.packet);
auto &p = entry.second.packet;
if (p.Length() >= DaybreakHeader::size()) {
if (p.GetInt8(0) == 0 && p.GetInt8(1) >= OP_Fragment && p.GetInt8(1) <= OP_Fragment4) {
m_stats.resent_fragments++;
}
else {
m_stats.resent_full++;
}
}
else {
m_stats.resent_full++;
}
m_stats.resent_packets++;
InternalBufferedSend(p);
entry.second.last_sent = now;
entry.second.times_resent++;
entry.second.resend_delay = EQEmu::Clamp(entry.second.resend_delay * 2, m_owner->m_options.resend_delay_min, m_owner->m_options.resend_delay_max);
@ -1091,6 +1156,12 @@ void EQ::Net::DaybreakConnection::OutOfOrderAck(int stream, uint16_t seq)
}
}
void EQ::Net::DaybreakConnection::UpdateDataBudget(double budget_add)
{
auto outgoing_data_rate = m_owner->m_options.outgoing_data_rate;
m_outgoing_budget = EQEmu::ClampUpper(m_outgoing_budget + budget_add, outgoing_data_rate);
}
void EQ::Net::DaybreakConnection::SendAck(int stream_id, uint16_t seq)
{
DaybreakReliableHeader ack;
@ -1181,6 +1252,14 @@ void EQ::Net::DaybreakConnection::SendKeepAlive()
void EQ::Net::DaybreakConnection::InternalSend(Packet &p)
{
if (m_owner->m_options.outgoing_data_rate >= 0.0) {
auto new_budget = m_outgoing_budget - (p.Length() / 1024.0);
if (new_budget <= 0.0) {
m_stats.dropped_datarate_packets++;
return;
}
}
m_last_send = Clock::now();
auto send_func = [](uv_udp_send_t* req, int status) {

View File

@ -78,19 +78,35 @@ namespace EQ
sent_bytes = 0;
recv_packets = 0;
sent_packets = 0;
sync_recv_packets = 0;
sync_sent_packets = 0;
sync_remote_recv_packets = 0;
sync_remote_sent_packets = 0;
min_ping = 0xFFFFFFFFFFFFFFFFUL;
max_ping = 0;
created = Clock::now();
dropped_datarate_packets = 0;
resent_packets = 0;
resent_fragments = 0;
resent_full = 0;
}
uint64_t recv_bytes;
uint64_t sent_bytes;
uint64_t recv_packets;
uint64_t sent_packets;
uint64_t sync_recv_packets;
uint64_t sync_sent_packets;
uint64_t sync_remote_recv_packets;
uint64_t sync_remote_sent_packets;
uint64_t min_ping;
uint64_t max_ping;
uint64_t last_ping;
Timestamp created;
uint64_t dropped_datarate_packets; //packets dropped due to datarate limit, couldn't think of a great name
uint64_t resent_packets;
uint64_t resent_fragments;
uint64_t resent_full;
};
class DaybreakConnectionManager;
@ -110,8 +126,7 @@ namespace EQ
void QueuePacket(Packet &p, int stream);
void QueuePacket(Packet &p, int stream, bool reliable);
const DaybreakConnectionStats& GetStats() const { return m_stats; }
DaybreakConnectionStats &GetStats() { return m_stats; }
DaybreakConnectionStats GetStats();
void ResetStats();
size_t GetRollingPing() const { return m_rolling_ping; }
DbProtocolStatus GetStatus() const { return m_status; }
@ -140,6 +155,7 @@ namespace EQ
Timestamp m_last_session_stats;
size_t m_rolling_ping;
Timestamp m_close_time;
double m_outgoing_budget;
struct DaybreakSentPacket
{
@ -191,6 +207,7 @@ namespace EQ
void ProcessResend(int stream);
void Ack(int stream, uint16_t seq);
void OutOfOrderAck(int stream, uint16_t seq);
void UpdateDataBudget(double budget_add);
void SendConnect();
void SendKeepAlive();
@ -230,6 +247,7 @@ namespace EQ
tic_rate_hertz = 60.0;
resend_timeout = 90000;
connection_close_time = 2000;
outgoing_data_rate = 8.0;
}
size_t max_packet_size;
@ -252,6 +270,7 @@ namespace EQ
size_t connection_close_time;
DaybreakEncodeType encode_passes[2];
int port;
double outgoing_data_rate;
};
class DaybreakConnectionManager
@ -263,6 +282,7 @@ namespace EQ
void Connect(const std::string &addr, int port);
void Process();
void UpdateDataBudget();
void ProcessResend();
void OnNewConnection(std::function<void(std::shared_ptr<DaybreakConnection>)> func) { m_on_new_connection = func; }
void OnConnectionStateChange(std::function<void(std::shared_ptr<DaybreakConnection>, DbProtocolStatus, DbProtocolStatus)> func) { m_on_connection_state_change = func; }

View File

@ -130,11 +130,11 @@ void EQ::Net::EQStream::Close() {
std::string EQ::Net::EQStream::GetRemoteAddr() const
{
return RemoteEndpoint();
return GetRawConnection()->RemoteEndpoint();
}
uint32 EQ::Net::EQStream::GetRemoteIP() const {
return inet_addr(RemoteEndpoint().c_str());
return inet_addr(GetRawConnection()->RemoteEndpoint().c_str());
}
bool EQ::Net::EQStream::CheckState(EQStreamState state) {
@ -177,23 +177,23 @@ EQStreamInterface::MatchState EQ::Net::EQStream::CheckSignature(const Signature
if (opcode == sig->first_eq_opcode) {
if (length == sig->first_length) {
LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} and length matched {3}",
RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length);
GetRawConnection()->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length);
return MatchSuccessful;
}
else if (length == 0) {
LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} and length is ignored.",
RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode);
GetRawConnection()->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode);
return MatchSuccessful;
}
else {
LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode matched {2:#x} but length {3} did not match expected {4}",
RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length, sig->first_length);
GetRawConnection()->RemoteEndpoint(), m_connection->RemotePort(), sig->first_eq_opcode, length, sig->first_length);
return MatchFailed;
}
}
else {
LogF(Logs::General, Logs::Netcode, "[IDENT_TRACE] {0}:{1}: First opcode {1:#x} did not match expected {2:#x}",
RemoteEndpoint(), m_connection->RemotePort(), opcode, sig->first_eq_opcode);
GetRawConnection()->RemoteEndpoint(), m_connection->RemotePort(), opcode, sig->first_eq_opcode);
return MatchFailed;
}
}
@ -213,4 +213,4 @@ EQStreamState EQ::Net::EQStream::GetState() {
default:
return CLOSED;
}
}
}

View File

@ -84,14 +84,9 @@ namespace EQ
m_opcode_manager = opm;
}
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection() {
virtual std::shared_ptr<EQ::Net::DaybreakConnection> GetRawConnection() const {
return m_connection;
}
const std::string& RemoteEndpoint() const { return m_connection->RemoteEndpoint(); }
const DaybreakConnectionStats& GetStats() const { return m_connection->GetStats(); }
void ResetStats() { m_connection->ResetStats(); }
size_t GetRollingPing() const { return m_connection->GetRollingPing(); }
private:
EQStreamManager *m_owner;
std::shared_ptr<DaybreakConnection> m_connection;

View File

@ -709,7 +709,7 @@ RULE_INT(Network, ResendDelayBaseMS, 100)
RULE_REAL(Network, ResendDelayFactor, 1.5)
RULE_INT(Network, ResendDelayMinMS, 100)
RULE_INT(Network, ResendDelayMaxMS, 5000)
RULE_INT(Network, ResendsPerCycle, 1000)
RULE_REAL(Network, ClientDataRate, 50.0) // 50KB / Sec
RULE_CATEGORY_END()
RULE_CATEGORY(QueryServ)

View File

@ -37,7 +37,7 @@ ClientManager::ClientManager()
}
titanium_stream->OnNewConnection([this](std::shared_ptr<EQ::Net::EQStream> stream) {
LogF(Logs::General, Logs::Login_Server, "New Titanium client connection from {0}:{1}", stream->RemoteEndpoint(), stream->GetRemotePort());
LogF(Logs::General, Logs::Login_Server, "New Titanium client connection from {0}:{1}", stream->GetRawConnection()->RemoteEndpoint(), stream->GetRemotePort());
stream->SetOpcodeManager(&titanium_ops);
Client *c = new Client(stream, cv_titanium);
clients.push_back(c);
@ -55,7 +55,7 @@ ClientManager::ClientManager()
}
sod_stream->OnNewConnection([this](std::shared_ptr<EQ::Net::EQStream> stream) {
LogF(Logs::General, Logs::Login_Server, "New SoD client connection from {0}:{1}", stream->RemoteEndpoint(), stream->GetRemotePort());
LogF(Logs::General, Logs::Login_Server, "New SoD client connection from {0}:{1}", stream->GetRawConnection()->RemoteEndpoint(), stream->GetRemotePort());
stream->SetOpcodeManager(&sod_ops);
Client *c = new Client(stream, cv_sod);
clients.push_back(c);

View File

@ -482,7 +482,7 @@ Clientlist::Clientlist(int ChatPort) {
exit(1);
chatsf->OnNewConnection([this](std::shared_ptr<EQ::Net::EQStream> stream) {
LogF(Logs::General, Logs::Login_Server, "New Client UDP connection from {0}:{1}", stream->RemoteEndpoint(), stream->GetRemotePort());
LogF(Logs::General, Logs::Login_Server, "New Client UDP connection from {0}:{1}", stream->GetRawConnection()->RemoteEndpoint(), stream->GetRemotePort());
stream->SetOpcodeManager(&ChatOpMgr);
auto c = new Client(stream);

View File

@ -502,6 +502,7 @@ int main(int argc, char** argv) {
opts.daybreak_options.resend_delay_factor = RuleR(Network, ResendDelayFactor);
opts.daybreak_options.resend_delay_min = RuleI(Network, ResendDelayMinMS);
opts.daybreak_options.resend_delay_max = RuleI(Network, ResendDelayMaxMS);
opts.daybreak_options.outgoing_data_rate = RuleR(Network, ClientDataRate);
EQ::Net::EQStreamManager eqsm(opts);
@ -520,7 +521,7 @@ int main(int argc, char** argv) {
eqsm.OnNewConnection([&stream_identifier](std::shared_ptr<EQ::Net::EQStream> stream) {
stream_identifier.AddStream(stream);
LogF(Logs::Detail, Logs::World_Server, "New connection from IP {0}:{1}", stream->RemoteEndpoint(), ntohs(stream->GetRemotePort()));
LogF(Logs::Detail, Logs::World_Server, "New connection from IP {0}:{1}", stream->GetRawConnection()->RemoteEndpoint(), ntohs(stream->GetRemotePort()));
});
while (RunLoops) {

View File

@ -55,6 +55,7 @@
#include "../common/say_link.h"
#include "../common/eqemu_logsys.h"
#include "../common/profanity_manager.h"
#include "../common/net/eqstream.h"
#include "data_bucket.h"
#include "command.h"
@ -9481,23 +9482,38 @@ void command_netstats(Client *c, const Seperator *sep)
{
if(c)
{
if(c->GetTarget() && c->GetTarget()->IsClient())
{
c->Message(0, "Sent:");
c->Message(0, "Total: %u, per second: %u", c->GetTarget()->CastToClient()->Connection()->GetBytesSent(),
c->GetTarget()->CastToClient()->Connection()->GetBytesSentPerSecond());
c->Message(0, "Recieved:");
c->Message(0, "Total: %u, per second: %u", c->GetTarget()->CastToClient()->Connection()->GetBytesRecieved(),
c->GetTarget()->CastToClient()->Connection()->GetBytesRecvPerSecond());
auto client = c;
if (c->GetTarget() && c->GetTarget()->IsClient()) {
client = c->GetTarget()->CastToClient();
}
}
else
{
c->Message(0, "Sent:");
c->Message(0, "Total: %u, per second: %u", c->Connection()->GetBytesSent(), c->Connection()->GetBytesSentPerSecond());
c->Message(0, "Recieved:");
c->Message(0, "Total: %u, per second: %u", c->Connection()->GetBytesRecieved(), c->Connection()->GetBytesRecvPerSecond());
}
auto connection = c->Connection();
auto stats = connection->GetRawConnection()->GetStats();
auto now = EQ::Net::Clock::now();
auto sec_since_stats_reset = std::chrono::duration_cast<std::chrono::duration<double>>(now - stats.created).count();
c->Message(0, "Netstats:");
c->Message(0, "--------------------------------------------------------------------");
c->Message(0, "Sent Bytes: %u (%.2f/sec)", stats.sent_bytes, stats.sent_bytes / sec_since_stats_reset);
c->Message(0, "Recv Bytes: %u (%.2f/sec)", stats.recv_bytes, stats.recv_bytes / sec_since_stats_reset);
c->Message(0, "Min Ping: %u", stats.min_ping);
c->Message(0, "Max Ping: %u", stats.max_ping);
c->Message(0, "Last Ping: %u", stats.last_ping);
c->Message(0, "--------------------------------------------------------------------");
c->Message(0, "(Realtime) Recv Packets: %u (%.2f/sec)", stats.recv_packets, stats.recv_packets / sec_since_stats_reset);
c->Message(0, "(Realtime) Sent Packets: %u (%.2f/sec)", stats.sent_packets, stats.sent_packets / sec_since_stats_reset);
c->Message(0, "(Sync) Recv Packets: %u", stats.sync_recv_packets);
c->Message(0, "(Sync) Sent Packets: %u", stats.sync_sent_packets);
c->Message(0, "(Sync) Remote Recv Packets: %u", stats.sync_remote_recv_packets);
c->Message(0, "(Sync) Remote Sent Packets: %u", stats.sync_remote_sent_packets);
c->Message(0, "Packet Loss In: %.2f%%", 100.0 * (1.0 - static_cast<double>(stats.sync_recv_packets) / static_cast<double>(stats.sync_remote_sent_packets)));
c->Message(0, "Packet Loss Out: %.2f%%", 100.0 * (1.0 - static_cast<double>(stats.sync_remote_recv_packets) / static_cast<double>(stats.sync_sent_packets)));
c->Message(0, "--------------------------------------------------------------------");
c->Message(0, "Resent Packets: %u (%.2f/sec)", stats.resent_packets, stats.resent_packets / sec_since_stats_reset);
c->Message(0, "Resent Fragments: %u (%.2f/sec)", stats.resent_fragments, stats.resent_fragments / sec_since_stats_reset);
c->Message(0, "Resent Non-Fragments: %u (%.2f/sec)", stats.resent_full, stats.resent_full / sec_since_stats_reset);
c->Message(0, "Dropped Datarate Packets: %u (%.2f/sec)", stats.dropped_datarate_packets, stats.dropped_datarate_packets / sec_since_stats_reset);
c->Message(0, "--------------------------------------------------------------------");
}
}

View File

@ -472,12 +472,13 @@ int main(int argc, char** argv) {
opts.daybreak_options.resend_delay_factor = RuleR(Network, ResendDelayFactor);
opts.daybreak_options.resend_delay_min = RuleI(Network, ResendDelayMinMS);
opts.daybreak_options.resend_delay_max = RuleI(Network, ResendDelayMaxMS);
opts.daybreak_options.outgoing_data_rate = RuleR(Network, ClientDataRate);
eqsm.reset(new EQ::Net::EQStreamManager(opts));
eqsf_open = true;
eqsm->OnNewConnection([&stream_identifier](std::shared_ptr<EQ::Net::EQStream> stream) {
stream_identifier.AddStream(stream);
LogF(Logs::Detail, Logs::World_Server, "New connection from IP {0}:{1}", stream->RemoteEndpoint(), ntohs(stream->GetRemotePort()));
LogF(Logs::Detail, Logs::World_Server, "New connection from IP {0}:{1}", stream->GetRawConnection()->RemoteEndpoint(), ntohs(stream->GetRemotePort()));
});
}