Many small adjustments to networking code

In an attempt to track down an issue that causes packet flooding and
hanging, I've looked at every step of the networking process and tried
to clean up anything strange I saw.

build-windows-visual-studio/sm64ex.sln

@@ -16,11 +16,9 @@ Global
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Debug|x64.ActiveCfg = Debug|x64
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Debug|x64.Build.0 = Debug|x64
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Debug|x86.ActiveCfg = Debug|Win32
-		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Debug|x86.Build.0 = Debug|Win32
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Release|x64.ActiveCfg = Release|x64
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Release|x64.Build.0 = Release|x64
 		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Release|x86.ActiveCfg = Release|Win32
-		{8ADFCAB9-E7D6-4588-86B5-A128DA4F811D}.Release|x86.Build.0 = Release|Win32
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE

build-windows-visual-studio/sm64ex.vcxproj

@@ -72,6 +72,8 @@
   <PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Debug|Win32'">
     <LinkIncremental>true</LinkIncremental>
     <IncludePath>../;../include/;../src/;$(IncludePath)</IncludePath>
+    <OutDir>$(SolutionDir)\..\build\us_pc\</OutDir>
+    <TargetName>sm64.us.f3dex2e</TargetName>
   </PropertyGroup>
   <PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Debug|x64'">
     <LinkIncremental>true</LinkIncremental>

build-windows-visual-studio/sm64ex.vcxproj.user

@@ -1,4 +1,7 @@
 <?xml version="1.0" encoding="utf-8"?>
 <Project ToolsVersion="Current" xmlns="http://schemas.microsoft.com/developer/msbuild/2003">
-  <PropertyGroup />
+  <PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Debug|Win32'">
+    <DebuggerFlavor>WindowsLocalDebugger</DebuggerFlavor>
+    <LocalDebuggerAttach>true</LocalDebuggerAttach>
+  </PropertyGroup>
 </Project>

src/pc/network/network.c

@@ -29,7 +29,6 @@ bool gNetworkAreaLoaded = false;
 bool gNetworkAreaSyncing = true;
 u32  gNetworkAreaTimer = 0;
 
-clock_t gLastNetworkSend = 0;
 struct StringLinkedList gRegisteredMods = { 0 };
 
 struct ServerSettings gServerSettings = {
@@ -114,8 +113,12 @@ void network_send_to(u8 localIndex, struct Packet* p) {
     if (gNetworkType == NT_NONE) { LOG_ERROR("network type error none!"); return; }
     if (p->error) { LOG_ERROR("packet error!"); return; }
     if (gNetworkSystem == NULL) { LOG_ERROR("no network system attached"); return; }
-    if (p->buffer[0] != PACKET_JOIN_REQUEST && p->buffer[0] != PACKET_KICK && p->buffer[0] != PACKET_ACK && gNetworkPlayerLocal != NULL && gNetworkPlayerServer->localIndex != gNetworkPlayerLocal->localIndex) {
+    if (localIndex == 0) {
-        assert(localIndex != gNetworkPlayerLocal->localIndex);
+        if (p->buffer[0] != PACKET_JOIN_REQUEST && p->buffer[0] != PACKET_KICK && p->buffer[0] != PACKET_ACK) {
+            LOG_ERROR("\n####################\nsending to myself, packetType: %d\n####################\n", p->packetType);
+            assert(false);
+            return;
+        }
     }
 
     if (gNetworkType == NT_SERVER) {
@@ -143,7 +146,7 @@ void network_send_to(u8 localIndex, struct Packet* p) {
     network_remember_reliable(p);
 
     // set ordered data (MUST BE IMMEDITAELY BEFORE HASING+SENDING)
-    if (p->orderedGroupId != 0) {
+    if (p->orderedGroupId != 0 && !p->sent) {
         packet_set_ordered_data(p);
     }
 
@@ -156,12 +159,14 @@ void network_send_to(u8 localIndex, struct Packet* p) {
         localIndex = gNetworkPlayerServer->localIndex;
     }
 
+    assert(p->dataLength < PACKET_LENGTH);
+
     // send
     int rc = gNetworkSystem->send(localIndex, p->buffer, p->cursor + sizeof(u32));
     if (rc == SOCKET_ERROR) { LOG_ERROR("send error %d", rc); return; }
     p->sent = true;
 
-    gLastNetworkSend = clock();
+    gNetworkPlayers[localIndex].lastSent = clock();
 }
 
 void network_send(struct Packet* p) {
@@ -174,7 +179,6 @@ void network_send(struct Packet* p) {
             int i = gNetworkPlayerServer->localIndex;
             p->localIndex = i;
             network_send_to(i, p);
-            gLastNetworkSend = clock();
             return;
         }
     }
@@ -194,7 +198,6 @@ void network_send(struct Packet* p) {
         p->localIndex = i;
         network_send_to(i, p);
     }
-    gLastNetworkSend = clock();
 }
 
 void network_receive(u8 localIndex, u8* data, u16 dataLength) {

src/pc/network/network.h

@@ -86,7 +86,6 @@ extern bool gNetworkAreaSyncing;
 extern u32 gNetworkAreaTimer;
 extern struct SyncObject gSyncObjects[];
 extern struct ServerSettings gServerSettings;
-extern clock_t gLastNetworkSend;
 extern struct StringLinkedList gRegisteredMods;
 
 // network.c

src/pc/network/network_player.c

@@ -80,19 +80,21 @@ struct NetworkPlayer* get_network_player_smallest_global(void) {
 }
 
 void network_player_update(void) {
-    float elapsed = (clock() - gLastNetworkSend) / (float)CLOCKS_PER_SEC;
-    if (elapsed > NETWORK_PLAYER_TIMEOUT / 3.0f) {
-        network_send_keep_alive();
-    }
 
-#ifndef DEVELOPMENT
+//#ifndef DEVELOPMENT
     if (gNetworkType == NT_SERVER) {
         for (int i = 1; i < MAX_PLAYERS; i++) {
             struct NetworkPlayer* np = &gNetworkPlayers[i];
             if (!np->connected) { continue; }
             float elapsed = (clock() - np->lastReceived) / (float)CLOCKS_PER_SEC;
             if (elapsed > NETWORK_PLAYER_TIMEOUT) {
+                LOG_INFO("dropping player %d", i);
                 network_player_disconnected(i);
+                continue;
+            }
+            elapsed = (clock() - np->lastSent) / (float)CLOCKS_PER_SEC;
+            if (elapsed > NETWORK_PLAYER_TIMEOUT / 3.0f) {
+                network_send_keep_alive(np->localIndex);
             }
         }
     } else if (gNetworkType == NT_CLIENT) {
@@ -100,15 +102,23 @@ void network_player_update(void) {
         struct NetworkPlayer* np = gNetworkPlayerServer;
         if (!np->connected) { return; }
         float elapsed = (clock() - np->lastReceived) / (float)CLOCKS_PER_SEC;
+
         if (elapsed <= NETWORK_PLAYER_TIMEOUT * 1.5f) {
             connectionAlive = true;
             return;
         }
+
         if (!connectionAlive) {
+            LOG_INFO("dropping due to no server connectivity");
             network_shutdown();
         }
+
+        elapsed = (clock() - np->lastSent) / (float)CLOCKS_PER_SEC;
+        if (elapsed > NETWORK_PLAYER_TIMEOUT / 3.0f) {
+            network_send_keep_alive(np->localIndex);
+        }
     }
-#endif
+//#endif
 }
 
 u8 network_player_connected(enum NetworkPlayerType type, u8 globalIndex) {
@@ -149,6 +159,7 @@ u8 network_player_connected(enum NetworkPlayerType type, u8 globalIndex) {
             if (np->globalIndex != globalIndex) { continue; }
             np->localIndex = i;
             np->lastReceived = clock();
+            np->lastSent = clock();
             if (gNetworkType == NT_SERVER || type == NPT_SERVER) { gNetworkSystem->save_id(i, 0); }
             LOG_ERROR("player connected, reusing local %d, global %d, duplicate event?", i, globalIndex);
             return i;
@@ -174,6 +185,7 @@ u8 network_player_connected(enum NetworkPlayerType type, u8 globalIndex) {
         np->globalIndex = (gNetworkType == NT_SERVER) ? i : globalIndex;
         np->type = type;
         np->lastReceived = clock();
+        np->lastSent = clock();
         if (gNetworkType == NT_SERVER || type == NPT_SERVER) { gNetworkSystem->save_id(i, 0); }
         for (int j = 0; j < MAX_SYNC_OBJECTS; j++) { gSyncObjects[j].rxEventId[i] = 0; }
         if (type == NPT_SERVER) { gNetworkPlayerServer = np; }

src/pc/network/network_player.h

@@ -23,6 +23,7 @@ struct NetworkPlayer {
     u8 localIndex;
     u8 globalIndex;
     clock_t lastReceived;
+    clock_t lastSent;
     u16 currLevelAreaSeqId;
     s16 currCourseNum;
     s16 currActNum;

src/pc/network/packets/packet.h

@@ -177,7 +177,7 @@ void network_send_kick(enum KickReasonType kickReason);
 void network_receive_kick(struct Packet* p);
 
 // packet_keep_alive.c
-void network_send_keep_alive(void);
+void network_send_keep_alive(u8 localIndex);
 void network_receive_keep_alive(struct Packet* p);
 
 // packet_leaving.c

src/pc/network/packets/packet_join.c

@@ -38,12 +38,6 @@ void network_receive_join_request(struct Packet* p) {
 void network_send_join(struct Packet* joinRequestPacket) {
     assert(gNetworkType == NT_SERVER);
 
-    fs_file_t* fp = fs_open(SAVE_FILENAME);
-    if (fp != NULL) {
-        fs_read(fp, eeprom, 512);
-        fs_close(fp);
-    }
-
     // do connection event
     joinRequestPacket->localIndex = network_player_connected(NPT_CLIENT, joinRequestPacket->localIndex);
     if (joinRequestPacket->localIndex == UNKNOWN_LOCAL_INDEX) {
@@ -51,6 +45,12 @@ void network_send_join(struct Packet* joinRequestPacket) {
         return;
     }
 
+    fs_file_t* fp = fs_open(SAVE_FILENAME);
+    if (fp != NULL) {
+        fs_read(fp, eeprom, 512);
+        fs_close(fp);
+    }
+
     char version[MAX_VERSION_LENGTH] = { 0 };
     snprintf(version, MAX_VERSION_LENGTH, "%s", get_version());
     LOG_INFO("sending version: %s", version);

src/pc/network/packets/packet_keep_alive.c

@@ -2,15 +2,10 @@
 #include "../network.h"
 #include "pc/debuglog.h"
 
-void network_send_keep_alive(void) {
+void network_send_keep_alive(u8 localIndex) {
     struct Packet p;
     packet_init(&p, PACKET_KEEP_ALIVE, false, false);
-    if (gNetworkType == NT_SERVER) {
+    network_send_to(localIndex, &p);
-        network_send(&p);
-    } else {
-        network_send_to(gNetworkPlayerServer->localIndex, &p);
-    }
-    gLastNetworkSend = clock();
     LOG_INFO("sending keep alive");
 }
 

src/pc/network/packets/packet_level_respawn_info.c

@@ -126,7 +126,7 @@ void network_send_level_respawn_info(struct Object* o, u8 respawnInfoBits) {
     // send the packet
     if (gNetworkType == NT_SERVER) {
         // broadcast
-        for (int i = 0; i < MAX_PLAYERS; i++) {
+        for (int i = 1; i < MAX_PLAYERS; i++) {
             struct NetworkPlayer* np = &gNetworkPlayers[i];
             if (!np->connected)                      { continue; }
             if (!np->currLevelSyncValid)             { continue; }
@@ -174,7 +174,7 @@ void network_receive_level_respawn_info(struct Packet* p) {
         }
 
         // broadcast this change to the other players in that level
-        for (int i = 0; i < MAX_PLAYERS; i++) {
+        for (int i = 1; i < MAX_PLAYERS; i++) {
             struct NetworkPlayer* np = &gNetworkPlayers[i];
             if (!np->connected) { continue; }
             if (!np->currLevelSyncValid) { continue; }

src/pc/network/packets/packet_read_write.c

@@ -14,6 +14,7 @@ static u8 sCurrentOrderedSeqId = 0;
 
 void packet_init(struct Packet* packet, enum PacketType packetType, bool reliable, bool levelAreaMustMatch) {
     memset(packet->buffer, 0, PACKET_LENGTH);
+    packet->packetType = packetType;
     packet->cursor = 0;
     packet->dataLength = 0;
     packet->error = false;
@@ -69,6 +70,7 @@ void packet_init(struct Packet* packet, enum PacketType packetType, bool reliabl
 
 void packet_duplicate(struct Packet* srcPacket, struct Packet* dstPacket) {
     memset(dstPacket->buffer, 0, PACKET_LENGTH);
+    dstPacket->packetType = srcPacket->packetType;
     dstPacket->cursor = 0;
     dstPacket->dataLength = 0;
     dstPacket->error = srcPacket->error;
@@ -90,6 +92,8 @@ void packet_duplicate(struct Packet* srcPacket, struct Packet* dstPacket) {
         dstPacket->seqId = sNextSeqNum;
         sNextSeqNum++;
         if (sNextSeqNum == 0) { sNextSeqNum++; }
+    } else {
+        dstPacket->seqId = 0;
     }
     memcpy(&dstPacket->buffer[1], &dstPacket->seqId, 2);
 

src/pc/network/packets/packet_reliable.c

@@ -101,8 +101,13 @@ void network_update_reliable(void) {
         float elapsed = (clock() - node->lastSend) / CLOCKS_PER_SEC;
         float maxElapsed = (node->sendAttempts * node->sendAttempts * RELIABLE_RESEND_RATE) / ((float)MAX_RESEND_ATTEMPTS);
         if (elapsed > maxElapsed) {
+            if (node->p.packetType == PACKET_JOIN_REQUEST && gNetworkPlayerServer != NULL) {
+                node->p.localIndex = gNetworkPlayerServer->localIndex;
+            }
             // resend
+            node->p.sent = true;
             network_send_to(node->p.localIndex, &node->p);
+
             node->lastSend = clock();
             node->sendAttempts++;
             if (node->sendAttempts >= MAX_RESEND_ATTEMPTS) {

src/pc/network/socket/socket.c

@@ -24,10 +24,12 @@ static int socket_bind(SOCKET socket, unsigned int port) {
 static int socket_send(SOCKET socket, struct sockaddr_in* addr, u8* buffer, u16 bufferLength) {
     int addrSize = sizeof(struct sockaddr_in);
     int rc = sendto(socket, (char*)buffer, bufferLength, 0, (struct sockaddr*)addr, addrSize);
-    if (rc == SOCKET_ERROR) {
+    if (rc != SOCKET_ERROR) { return NO_ERROR; }
-        LOG_ERROR("sendto failed with error: %d", SOCKET_LAST_ERROR);
-    }
 
+    int error = SOCKET_LAST_ERROR;
+    if (error == SOCKET_EWOULDBLOCK) { return NO_ERROR; }
+
+    LOG_ERROR("sendto failed with error: %d", error);
     return rc;
 }
 
@@ -49,7 +51,7 @@ static int socket_receive(SOCKET socket, struct sockaddr_in* rxAddr, u8* buffer,
         if (error != SOCKET_EWOULDBLOCK && error != SOCKET_ECONNRESET) {
             LOG_ERROR("recvfrom failed with error %d", SOCKET_LAST_ERROR);
         }
-        return rc;
+        return SOCKET_ERROR;
     }
 
     *receiveLength = rc;
@@ -118,10 +120,11 @@ static void ns_socket_update(void) {
     if (gNetworkType == NT_NONE) { return; }
     do {
         // receive packet
-        u8 data[PACKET_LENGTH];
+        u8 data[PACKET_LENGTH + 1];
         u16 dataLength = 0;
         u8 localIndex = UNKNOWN_LOCAL_INDEX;
-        int rc = socket_receive(curSocket, &addr[0], data, PACKET_LENGTH, &dataLength, &localIndex);
+        int rc = socket_receive(curSocket, &addr[0], data, PACKET_LENGTH + 1, &dataLength, &localIndex);
+        assert(dataLength < PACKET_LENGTH);
         if (rc != NO_ERROR) { break; }
         network_receive(localIndex, data, dataLength);
     } while (true);
@@ -132,7 +135,11 @@ static int ns_socket_send(u8 localIndex, u8* data, u16 dataLength) {
         if (gNetworkType == NT_SERVER && gNetworkPlayers[localIndex].type != NPT_CLIENT) { return SOCKET_ERROR; }
         if (gNetworkType == NT_CLIENT && gNetworkPlayers[localIndex].type != NPT_SERVER) { return SOCKET_ERROR; }
     }
-    return socket_send(curSocket, &addr[localIndex], data, dataLength);
+    int rc = socket_send(curSocket, &addr[localIndex], data, dataLength);
+    if (rc) {
+        LOG_ERROR("    localIndex: %d, packetType: %d, dataLength: %d", localIndex, data[0], dataLength);
+    }
+    return rc;
 }
 
 static void ns_socket_shutdown(void) {

src/pc/pc_main.c

@@ -311,7 +311,9 @@ void main_func(void) {
 #ifdef DISCORDRPC
         discord_update_rich_presence();
 #endif
+#ifdef DEBUG
         fflush(stdout);
+#endif
     }
 #endif
 }