jepler/fruitjam-doom
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

net: Add logging of server events.

Browse source
This commit is contained in:
Simon Howard 2019-01-27 23:36:50 -05:00
parent 124ca83db4
commit 31accc834d
1 changed files with 113 additions and 43 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

156
src/net_server.c
View file

@ -483,7 +483,7 @@ static void NET_SV_AdvanceWindow(void)
// Advance the recv window until it catches up with lowtic
while (recvwindow_start < lowtic)
{
{
boolean should_advance;
// Check we have tics from all players for first tic in
@ -520,8 +520,7 @@ static void NET_SV_AdvanceWindow(void)
sizeof(*recvwindow) * (BACKUPTICS - 1));
memset(&recvwindow[BACKUPTICS-1], 0, sizeof(*recvwindow));
++recvwindow_start;
//printf("SV: advanced to %i\n", recvwindow_start);
NET_Log("server: advanced receive window to %d", recvwindow_start);
}
}
@ -550,6 +549,8 @@ static void NET_SV_SendReject(net_addr_t *addr, const char *msg)
{
net_packet_t *packet;
NET_Log("server: sending reject to %s", NET_AddrToString(addr));
packet = NET_NewPacket(10);
NET_WriteInt16(packet, NET_PACKET_TYPE_REJECTED);
NET_WriteString(packet, msg);
@ -576,6 +577,8 @@ static void NET_SV_InitNewClient(net_client_t *client, net_addr_t *addr,
client->last_gamedata_time = 0;
memset(client->sendqueue, 0xff, sizeof(client->sendqueue));
NET_Log("server: initialized new client from %s", NET_AddrToString(addr));
}
// parse a SYN from a client(initiating a connection)
@ -592,9 +595,12 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
int num_players;
int i;
NET_Log("server: processing SYN packet");
// Read the magic number and check it is the expected one.
if (!NET_ReadInt32(packet, &magic))
{
NET_Log("server: error: no magic number for SYN");
return;
}
@ -604,12 +610,14 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
break;
case NET_OLD_MAGIC_NUMBER:
NET_Log("server: error: client using old magic number: %d", magic);
NET_SV_SendReject(addr,
"You are using an old client version that is not supported by "
"this server. This server is running " PACKAGE_STRING ".");
return;
default:
NET_Log("server: error: wrong magic number: %d", magic);
return;
}
@ -619,6 +627,7 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
client_version = NET_ReadString(packet);
if (client_version == NULL)
{
NET_Log("server: error: no version from client");
return;
}
@ -635,15 +644,24 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
"client is: %s. No common compatible protocol could be "
"negotiated.", client_version);
NET_SV_SendReject(addr, reject_msg);
NET_Log("server: error: no common protocol");
return;
}
// Read connect data, and check that the game mode/mission are valid
// and the max_players value is in a sensible range.
if (!NET_ReadConnectData(packet, &data)
|| !D_ValidGameMode(data.gamemission, data.gamemode)
if (!NET_ReadConnectData(packet, &data))
{
NET_Log("server: error: failed to read connect data");
return;
}
if (!D_ValidGameMode(data.gamemission, data.gamemode)
|| data.max_players > NET_MAXPLAYERS)
{
NET_Log("server: error: invalid connect data, max_players=%d, "
"gamemission=%d, gamemode=%d",
data.max_players, data.gamemission, data.gamemode);
return;
}
@ -651,6 +669,7 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
player_name = NET_ReadString(packet);
if (player_name == NULL)
{
NET_Log("server: error: failed to read player name");
return;
}
@ -659,6 +678,8 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
// Not accepting new connections?
if (server_state != SERVER_WAITING_LAUNCH)
{
NET_Log("server: error: not in waiting launch state, server_state=%d",
server_state);
NET_SV_SendReject(addr,
"Server is not currently accepting connections");
return;
@ -671,6 +692,8 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
if ((!data.drone && num_players >= NET_SV_MaxPlayers())
|| NET_SV_NumClients() >= MAXNETNODES)
{
NET_Log("server: no more players, num_players=%d, max=%d",
num_players, NET_SV_MaxPlayers());
NET_SV_SendReject(addr, "Server is full!");
return;
}
@ -684,6 +707,8 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
{
sv_gamemode = data.gamemode;
sv_gamemission = data.gamemission;
NET_Log("server: new game, mode=%d, mission=%d",
sv_gamemode, sv_gamemission);
}
// Check the connecting client is playing the same game as all
@ -691,6 +716,8 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
if (data.gamemode != sv_gamemode || data.gamemission != sv_gamemission)
{
char msg[128];
NET_Log("server: wrong mode/mission, %d != %d || %d != %d",
data.gamemode, sv_gamemode, data.gamemission, sv_gamemission);
M_snprintf(msg, sizeof(msg),
"Game mismatch: server is %s (%s), client is %s (%s)",
D_GameMissionString(sv_gamemission),
@ -735,6 +762,7 @@ static void NET_SV_ParseSYN(net_packet_t *packet, net_client_t *client,
// Client already connected?
if (client->active)
{
NET_Log("server: client is already initialized (duplicate SYN?)");
return;
}
@ -767,10 +795,14 @@ static void NET_SV_ParseLaunch(net_packet_t *packet, net_client_t *client)
int num_players;
unsigned int i;
NET_Log("server: processing launch packet");
// Only the controller can launch the game.
if (client != NET_SV_Controller())
{
NET_Log("server: error: this client isn't the controller, %d != %d",
client, NET_SV_Controller());
return;
}
@ -778,11 +810,13 @@ static void NET_SV_ParseLaunch(net_packet_t *packet, net_client_t *client)
if (server_state != SERVER_WAITING_LAUNCH)
{
NET_Log("server: error: not in waiting launch state, state=%d",
server_state);
return;
}
// Forward launch on to all clients.
NET_Log("server: sending launch to all clients");
NET_SV_AssignPlayers();
num_players = NET_SV_NumPlayers();
@ -863,7 +897,7 @@ static void StartGame(void)
}
// Change server state
NET_Log("server: beginning game state");
server_state = SERVER_IN_GAME;
memset(recvwindow, 0, sizeof(recvwindow));
@ -891,10 +925,14 @@ static boolean AllNodesReady(void)
static void CheckStartGame(void)
{
if (AllNodesReady())
if (!AllNodesReady())
{
StartGame();
NET_Log("server: not all clients ready to start yet");
return;
}
NET_Log("server: all clients ready, starting game");
StartGame();
}
// Send waiting data with current status to all nodes that are ready to
@ -919,10 +957,14 @@ static void NET_SV_ParseGameStart(net_packet_t *packet, net_client_t *client)
{
net_gamesettings_t settings;
NET_Log("server: processing game start packet");
// Can only start a game if we are in the waiting start state.
if (server_state != SERVER_WAITING_START)
{
NET_Log("server: error: not in waiting start state, server_state=%d",
server_state);
return;
}
@ -931,7 +973,7 @@ static void NET_SV_ParseGameStart(net_packet_t *packet, net_client_t *client)
if (!NET_ReadSettings(packet, &settings))
{
// Malformed packet
NET_Log("server: error: no settings from controller");
return;
}
@ -939,6 +981,7 @@ static void NET_SV_ParseGameStart(net_packet_t *packet, net_client_t *client)
if (!NET_ValidGameSettings(sv_gamemode, sv_gamemission, &settings))
{
NET_Log("server: error: invalid game settings");
return;
}
@ -966,7 +1009,8 @@ static void NET_SV_SendResendRequest(net_client_t *client, int start, int end)
unsigned int nowtime;
int index;
//printf("SV: send resend for %i-%i\n", start, end);
NET_Log("server: send resend to %s for tics %d-%d",
NET_AddrToString(client->addr), start, end);
packet = NET_NewPacket(20);
@ -1030,33 +1074,36 @@ static void NET_SV_CheckResends(net_client_t *client)
if (need_resend)
{
// Start a new run of resend tics?
if (resend_start < 0)
{
resend_start = i;
}
resend_end = i;
}
else
else if (resend_start >= 0)
{
if (resend_start >= 0)
{
// End of a run of resend tics
// End of a run of resend tics
NET_Log("server: resend request to %s timed out for %d-%d (%d)",
NET_AddrToString(client->addr),
recvwindow_start + resend_start,
recvwindow_start + resend_end,
&recvwindow[resend_start][player].resend_time);
NET_SV_SendResendRequest(client,
recvwindow_start + resend_start,
recvwindow_start + resend_end);
//printf("SV: resend request timed out: %i-%i\n", resend_start, resend_end);
NET_SV_SendResendRequest(client,
recvwindow_start + resend_start,
recvwindow_start + resend_end);
resend_start = -1;
}
resend_start = -1;
}
}
if (resend_start >= 0)
{
NET_SV_SendResendRequest(client,
NET_Log("server: resend request to %s timed out for %d-%d (%d)",
NET_AddrToString(client->addr),
recvwindow_start + resend_start,
recvwindow_start + resend_end,
&recvwindow[resend_start][player].resend_time);
NET_SV_SendResendRequest(client,
recvwindow_start + resend_start,
recvwindow_start + resend_end);
}
@ -1078,32 +1125,36 @@ static void NET_SV_ParseGameData(net_packet_t *packet, net_client_t *client)
if (server_state != SERVER_IN_GAME)
{
NET_Log("server: error: not in game state: server_state=%d",
server_state);
return;
}
if (client->drone)
{
// Drones do not contribute any game data.
NET_Log("server: error: game data from a drone?");
return;
}
player = client->player_number;
// Read header
if (!NET_ReadInt8(packet, &ackseq)
|| !NET_ReadInt8(packet, &seq)
|| !NET_ReadInt8(packet, &num_tics))
{
NET_Log("server: error: failed to read header");
return;
}
// Get the current time
NET_Log("server: got game data, seq=%d, num_tics=%d, ackseq=%d",
seq, num_tics, ackseq);
// Get the current time
nowtime = I_GetTimeMS();
// Expand 8-bit values to the full sequence number
ackseq = NET_SV_ExpandTicNum(ackseq);
seq = NET_SV_ExpandTicNum(seq);
@ -1141,6 +1192,7 @@ static void NET_SV_ParseGameData(net_packet_t *packet, net_client_t *client)
if (ackseq > client->acknowledged)
{
NET_Log("server: acknowledged up to %d", ackseq);
client->acknowledged = ackseq;
}
@ -1184,15 +1236,11 @@ static void NET_SV_ParseGameData(net_packet_t *packet, net_client_t *client)
}
// Possibly send a resend request
if (resend_start < resend_end)
{
/*
printf("missed %i-%i before %i, send resend\n",
recvwindow_start + resend_start,
recvwindow_start + resend_end - 1,
seq);
*/
NET_Log("server: request resend for %d-%d before %d",
recvwindow_start + resend_start,
recvwindow_start + resend_end - 1, seq);
NET_SV_SendResendRequest(client,
recvwindow_start + resend_start,
recvwindow_start + resend_end - 1);
@ -1203,8 +1251,12 @@ static void NET_SV_ParseGameDataACK(net_packet_t *packet, net_client_t *client)
{
unsigned int ackseq;
NET_Log("server: processing game data ack packet");
if (server_state != SERVER_IN_GAME)
{
NET_Log("server: error: not in game state, server_state=%d",
server_state);
return;
}
@ -1212,6 +1264,7 @@ static void NET_SV_ParseGameDataACK(net_packet_t *packet, net_client_t *client)
if (!NET_ReadInt8(packet, &ackseq))
{
NET_Log("server: error: missing acknowledgement field");
return;
}
@ -1223,6 +1276,7 @@ static void NET_SV_ParseGameDataACK(net_packet_t *packet, net_client_t *client)
if (ackseq > client->acknowledged)
{
NET_Log("server: acknowledged up to %d", ackseq);
client->acknowledged = ackseq;
}
}
@ -1275,11 +1329,14 @@ static void NET_SV_ParseResendRequest(net_packet_t *packet, net_client_t *client
unsigned int num_tics;
unsigned int i;
NET_Log("server: processing resend request");
// Read the starting tic and number of tics
if (!NET_ReadInt32(packet, &start)
|| !NET_ReadInt8(packet, &num_tics))
{
NET_Log("server: error: missing fields for resend");
return;
}
@ -1301,13 +1358,14 @@ static void NET_SV_ParseResendRequest(net_packet_t *packet, net_client_t *client
// This is pretty fatal. We could disconnect the client,
// but then again this could be a spoofed packet. Just
// ignore it.
NET_Log("server: error: don't have tic %d any more, "
"can't resend", i);
return;
}
}
// Resend those tics
NET_Log("server: resending tics %d-%d", start, last);
NET_SV_SendTics(client, start, last);
}
@ -1356,7 +1414,7 @@ void NET_SV_SendQueryResponse(net_addr_t *addr)
}
// Send it and we're done.
NET_Log("server: sending query response to %s", NET_AddrToString(addr));
reply = NET_NewPacket(64);
NET_WriteInt16(reply, NET_PACKET_TYPE_QUERY_RESPONSE);
NET_WriteQueryData(reply, &querydata);
@ -1392,6 +1450,10 @@ static void NET_SV_Packet(net_packet_t *packet, net_addr_t *addr)
return;
}
NET_Log("server: packet from %s; type %d", NET_AddrToString(addr),
packet_type & ~NET_RELIABLE_PACKET);
NET_LogPacket(packet);
if (packet_type == NET_PACKET_TYPE_SYN)
{
NET_SV_ParseSYN(packet, client, addr);
@ -1512,8 +1574,6 @@ static void NET_SV_PumpSendQueue(net_client_t *client)
return;
}
//printf("SV: have complete ticcmd for %i\n", client->sendseq);
// We have all data we need to generate a command for this tic.
cmd.seq = client->sendseq;
@ -1564,6 +1624,8 @@ static void NET_SV_PumpSendQueue(net_client_t *client)
if (starttic < 0)
starttic = 0;
NET_Log("server: send tics %d-%d to %s", starttic, endtic,
NET_AddrToString(client->addr));
NET_SV_SendTics(client, starttic, endtic);
++client->sendseq;
@ -1594,6 +1656,10 @@ void NET_SV_CheckDeadlock(net_client_t *client)
if (nowtime - client->last_gamedata_time > 1000)
{
NET_Log("server: no gamedata from %s since %d - deadlock?",
NET_AddrToString(client->addr),
client->last_gamedata_time);
// Search the receive window for the first tic we are expecting
// from this player.
@ -1601,7 +1667,8 @@ void NET_SV_CheckDeadlock(net_client_t *client)
{
if (!recvwindow[client->player_number][i].active)
{
//printf("Possible deadlock: Sending resend request\n");
NET_Log("server: deadlock: sending resend request for %d-%d",
recvwindow_start + i, recvwindow_start + i + 5);
// Found a tic we haven't received. Send a resend request.
@ -1642,14 +1709,16 @@ static void NET_SV_RunClient(net_client_t *client)
// Run common code
NET_Conn_Run(&client->connection);
if (client->connection.state == NET_CONN_STATE_DISCONNECTED
&& client->connection.disconnect_reason == NET_DISCONNECT_TIMEOUT)
{
NET_Log("server: client at %s timed out",
NET_AddrToString(client->addr));
NET_SV_BroadcastMessage("Client '%s' timed out and disconnected",
client->name);
}
// Is this client disconnected?
if (client->connection.state == NET_CONN_STATE_DISCONNECTED)
@ -1677,6 +1746,7 @@ static void NET_SV_RunClient(net_client_t *client)
if (NET_SV_NumPlayers() <= 0)
{
NET_Log("server: no player clients left, game ended");
NET_SV_GameEnded();
}
}