pvpgn / pvpgn-server

Next generation of PvPGN server
https://pvpgn.pro
GNU General Public License v2.0
555 stars 156 forks source link

pvpgn::packet_get_size (connection interrupted) #491

Open sharpwg1337 opened 6 months ago

sharpwg1337 commented 6 months ago

Greetings,

I was wondering if there was any way to discern what could cause "Connection has been interrupted" randomly in-game (but VERY frequently. Always within 10 minutes of the game start, usually within 5).

This is version 1.13c (client and server).

I have gotten it in several areas, across several characters, and it "seems" to be random. I don't seem to be doing anything specific when it happens.

That is, is this a very tricky one to solve or is there some log file that would contain more specific information? I have looked at my D2GS logs (although I am not sure if this is a PVPGN problem or D2GS problem).

In D2GS.log you can see I enter a game, play for a while, then it closes the game:

05/01 11:05:53.869 D2GSCBSaveDatabaseCharacter: Save CHARSAVE for Zod(*cham)
05/01 11:05:53.869 D2GSUpdateCharacterLadder: Update ladder for Zod@D2
05/01 11:05:53.876 D2DBSSaveDataReply: Save <CHARSAVE> data to D2DBS for Zod success
05/01 11:11:21.547 D2GSCBSaveDatabaseCharacter: Save CHARSAVE for Zod(*cham)
05/01 11:11:21.547 D2GSUpdateCharacterLadder: Update ladder for Zod@D2
05/01 11:11:21.552 D2GSCBLeaveGame: Zod(*cham)[L=89,C=Sor] leave game 'Wat', id=4(exp,hell,softcore,ladder)
05/01 11:11:21.552 D2GSSendNetData: send failed, code: 10054
05/01 11:11:21.552 D2GSWriteCharInfoFile: Send CHARINFO data for Zod(*cham)
05/01 11:11:21.552 D2GSSendNetData: send failed, code: 10054
05/01 11:11:21.552 D2GSSetCharLockStatus: Set charlock status to UNLOCKED for Zod(*cham)@D2
05/01 11:11:21.552 D2GSCBCloseGame: Close game 'Wat', id=4(exp,hell,softcore,ladder)
05/01 11:11:21.552 D2GSDeleteAllCharInGame: Delete 0(0) character in game 'Wat' (4)
05/01 11:11:21.564 CloseConnectionToD2CS: Close Connection to D2CS
05/01 11:11:26.568 CloseConnectionToD2DBS: Close Connection to D2DBS
05/01 11:11:26.571 D2GSConnectToD2xS: Connected to D2DBS Successfully
05/01 11:11:26.571 D2GSSendClassToD2DBS: Send connection class packet to D2DBS
05/01 11:11:26.575 D2GSConnectToD2xS: Connected to D2CS Successfully
05/01 11:11:26.576 D2GSSendClassToD2CS: Send connection class packet to D2CS
05/01 11:11:26.577 D2GSNetRecvPacket: CS socket become writable
05/01 11:11:26.577 D2GSAuthreq: Auth request for 'D2'
05/01 11:11:26.577 D2GSNetRecvPacket: DBS socket become writable
05/01 11:11:26.583 D2GSAuthReply: Game Server Activated by D2CS
05/01 11:11:26.583 D2GSSetD2CSMaxGameNumber: Tell D2CS to set max game to 100
05/01 11:11:26.583 D2GSSetGameInfoByD2CS: Set current maxgame to 100

The only "error" I can see is:

D2GSSendNetData: send failed, code: 10054 (twice)

All the services are running on the same machine. I am connecting to the realm locally as well, at the moment.

The only mod I have is BaseMod which is loaded from a custom MPQ (a large portion of the features are disabled) and I also modified the Patch_D2.mpq bin files to adjust some drop rates.

I found this in d2dbs.log under PVPGN:

May 01 11:00:26 [info ] pvpgn::d2dbs::dbs_packet_getdata: lock char Zod(*cham)@D2 for gs 192.168.1.12(1)
May 01 11:00:26 [info ] pvpgn::d2dbs::dbs_packet_getdata_charsave: loaded charsave zod(*cham) for gs 192.168.1.12(1)
May 01 11:00:26 [info ] pvpgn::d2dbs::dbs_packet_getdata_charinfo: loaded charinfo zod(*cham) for gs 192.168.1.12(1)
May 01 11:05:53 [info ] pvpgn::d2dbs::dbs_packet_savedata_charsave: saved charsave zod(*cham) for gs 192.168.1.12(1)
May 01 11:05:53 [info ] pvpgn::d2dbs::dbs_packet_updateladder: update ladder for Zod@D2 for gs 192.168.1.12(1)
May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136
May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136
May 01 11:11:21 [warn ] pvpgn::net_recv_packet: [648] corrupted packet received (total_size=0 currsize=8) (closing connection)
May 01 11:11:21 [debug] pvpgn::d2dbs::sd_tcpinput: [648] read returned -1 (closing connection)
May 01 11:11:21 [info ] pvpgn::d2dbs::conn_destroy: [648] unlock all characters on gs 192.168.1.12(1)
May 01 11:11:21 [info ] pvpgn::d2dbs::conn_destroy: [648] closed d2gs connection
Could this portion be the cause and is there any way to determine how/why this happened?

May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136
May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136
May 01 11:11:21 [warn ] pvpgn::net_recv_packet: [648] corrupted packet received (total_size=0 currsize=8) (closing connection)

May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136 May 01 11:11:21 [error] pvpgn::packet_get_size: packet has bad size 3136

The above seems to be the cause. Is there any fix. I compiled this about a week ago using the develop branch at the time.

s-montigny-desautels commented 5 months ago

I don't know if you resolved your issue, this fix worked for me:

You need to update the following file src/common/field_sizes.h and change the line 21 (variable MAX_PACKET_SIZE) to a greater value.

Here is a patch for it

diff --git a/src/common/field_sizes.h b/src/common/field_sizes.h
index de46a1f..ed493bc 100644
--- a/src/common/field_sizes.h
+++ b/src/common/field_sizes.h
@@ -18,7 +18,7 @@
 #ifndef INCLUDED_FIELD_SIZES_TYPES
 #define INCLUDED_FIELD_SIZES_TYPES

-const unsigned MAX_PACKET_SIZE = 3072;
+const unsigned MAX_PACKET_SIZE = 65535;
 const unsigned MAX_WOL_GAMERES_PACKET_SIZE = 65535;
 const unsigned MAX_NORMAL_TYPE = 0xffff;
 const unsigned MAX_FILE_TYPE = 0xffff;

With this change, my server is running smoothly since the last two weeks.