Starting Work on SoF Opcodes/Structs

[trevius]

Ya, I figure if worse comes to worse, at least I am learning something along the way, which is always a good thing

My current plan is to find as many opcodes as I can. I think once I get the hang of it, it won't be too bad to find many of them. As long as I can get the important ones going, then I can move onto the next step. The next step will be to see if I can figure out how to collect packet structures from EQLive, and then compare the Titanium structures to the Live structures and see if I can figure out what might work for SoF. I imagine that the structures from SoF are still fairly close to Live in alot of ways. By looking at the added features from each expansion, it might not be too hard to figure out what to add/remove and where. I think then the main issue will be making sure that everything takes up the correct space in the structs, since that will be hard to guess. Once the old and new structures are compared, we can probably narrow it down to a few questionable pieces and try to resolve those. I also think that SEQ source might be of some help. Though, I am not sure how exact their structures are for their releases.

Nothing ever gets done by lack of trying. Gotta start somewhere I guess, lol. I figure that if I can get a good start on this, maybe some people will see the progress and jump on board to help and finish it off quicker.

[KLS]

Also might be worth seeing if showEQ has a patch that matches with SoF client, not sure if you have or not. They usually figure out most of the really big structures and opcodes.

[trevius]

Ya, SoF was released on November 13, 2007 according to it's wiki page, and SEQ has patches for Nov 21, 28, and Dec 17. The Opcode update wasn't until Dec 17.

Here is the list of SEQ releases:
http://sourceforge.net/project/showf...ckage_id=13256

Here is a post about some changes after the expansion:
http://www.showeq.net/forums/showthr...3&page=5&pp=15

And more changes discussion after the patch here:
http://www.showeq.net/forums/showthr...?t=5943&page=4

The Opcodes I could find from the SEQ code don't seem to work. At least the ones I have tried so far. Though, I don't think they change them all with each patch, so maybe some of them will still work.

At least it looks like they have some good struct info, or at least something to work with. It is too bad our 2 projects don't really work together, because we could both share the load in working on stuff like this and EQEmu would have been updated long ago :P

Here are some of their change logs to give a timeframe idea of what they did and when:

ieatacid (1/21/0
----------------
+ Updated version to 5.12.1.0
+ Updated Opcodes
+ Updated structs (thanks ksmith for help with playerSpawnPosStruct bit fields)

BlueAdept (12/16/07)
----------------
+ Updated version to 5.12.0
+ Updated Opcodes (ieatacid)
+ Removed all the obfuscator stuff (ieatacid)

BlueAdept (11/21/07)
----------------
+ Updated version to 5.11.0
+ Updated structs (ieatacid)
+ Updated character level to 80 (ieatacid)

BlueAdept (11/05/07)
----------------
+ Updated version to 5.10.0
+ Added opcode decryption (purple, ieatacid)
+ Updated opcodes to current build
+ Changed version to correct numbering

So, it looks like we should be able to get at least some needed struct stuff from them, and maybe some opcodes, if they didn't all change by the time of the Dec 17th update.

[trevius]

Wow! I found some more good opcodes from the SEQ code that was just mislabelled on the date it was last updated. I finally made it to character select

[Mon Dec 08 04:07:32 2008]00035:WorldAuthenticate: Initiating Login.
[Mon Dec 08 04:07:40 2008]00036:WorldAuthenticate.  I got a message of type 0x4fb (1275).
[Mon Dec 08 04:07:40 2008]00037:WorldAuthenticate.  I got a message of type 0x129a (4762).
[Mon Dec 08 04:07:40 2008]00038:WorldRPServer message: server name stormhaven

[Mon Dec 08 04:07:40 2008]00039:WorldAuthenticate.  I got a message of type 0x7fc0 (32704).
[Mon Dec 08 04:07:40 2008]00040:WorldAuthenticate.  I got a message of type 0x1340 (4928).
[Mon Dec 08 04:07:40 2008]00041:WorldAuthenticate.  I got a message of type 0x1aee (6894).
[Mon Dec 08 04:07:40 2008]00042:WorldAuthenticate.  Access granted.

[Mon Dec 08 04:07:40 2008]00043:WorldAuthenticate.  I got a message of type 0xa1b (2587).

Here are the correct Opcodes so far:

#Required to reach Char Select:
OP_SendLoginInfo=0x6c3c		#SEQ 12/04/08
OP_ApproveWorld=0x7FC0		#SEQ 12/04/08
OP_LogServer=0x129A		#SEQ 12/04/08
OP_SendCharInfo=0x6040		#SEQ 12/04/08
OP_ExpansionInfo=0x0A1B		#SEQ 12/04/08
OP_GuildsList=0x04FB		#SEQ 12/04/08
OP_EnterWorld=0x1340		#SEQ 12/04/08
OP_PostEnterWorld=0x1AEE		#SEQ 12/04/08
OP_SendSpellChecksum=0x7A9E		#SEQ 12/04/08
OP_World_Client_CRC1=0x3795		#SEQ 12/04/08
OP_World_Client_CRC2=0x45F9		#SEQ 12/04/08

I found them in a file attached to this post:
http://www.showeq.net/forums/showthread.php?t=5975

Here is where it is failing now, from my EQ Log File:

[Mon Dec 08 04:09:12 2008]00194:THE SERVER IS NOT RESPONDING.
[Mon Dec 08 04:09:12 2008]00195:
end of DisplayScreen

[Mon Dec 08 04:09:14 2008]00196:TIMED OUT WAITING FOR ZONE ADDR

[Mon Dec 08 04:09:14 2008]00197:Networking: Connection Closed [0] with 0 pending bytes.

Not much info from there, but from the tail I am running on my server logs, I found this:

6825 [12.08. - 01:35:50] [NET__IDENT_TRACE] 192.168.1.101:3874: First opcode matched 0x6c3c and length matched 464
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] [OpCode OP_SendLoginInfo (0x6c3c) Size=464]
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x4fb (OP_GuildsList) and length 96064
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x00fe
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x129a (OP_LogServer) and length 264
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x00fd
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x7fc0 (OP_ApproveWorld) and length 544
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0108
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x1340 (OP_EnterWorld) and length 1
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0109
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x1aee (OP_PostEnterWorld) and length 0
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0103
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0xa1b (OP_ExpansionInfo) and length 4
6825 [12.08. - 01:35:50] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0102
6825 [12.08. - 01:35:50] [NET__APP_TRACE] Queueing acked packet with opcode 0x6040 (OP_SendCharInfo) and length 1589
6825 [12.08. - 01:35:58] [WORLD__CLIENT_TRACE] [OpCode OP_ApproveWorld (0x7fc0) Size=272]
6825 [12.08. - 01:36:07] Unable to convert EQ opcode 0x7a9e to an Application opcode.
6825 [12.08. - 01:36:07] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x7a9e) Size=2056]
6825 [12.08. - 01:36:07] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x7a9e) Size=2056]
6825 [12.08. - 01:36:07] [WORLD__CLIENT_TRACE] [OpCode OP_World_Client_CRC1 (0x3795) Size=2056]
6825 [12.08. - 01:36:07] Unable to convert EQ opcode 0x22cf to an Application opcode.
6825 [12.08. - 01:36:07] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x22cf) Size=2056]
6825 [12.08. - 01:36:07] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x22cf) Size=2056]
6825 [12.08. - 01:36:07] Unable to convert EQ opcode 0x43ba to an Application opcode.
6825 [12.08. - 01:36:07] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x43ba) Size=2056]
6825 [12.08. - 01:36:07] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x43ba) Size=2056]
6825 [12.08. - 01:36:33] Unable to convert EQ opcode 0x4d38 to an Application opcode.
6825 [12.08. - 01:36:33] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x4d38) Size=4]
6825 [12.08. - 01:36:33] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x4d38) Size=4]
6825 [12.08. - 01:36:33] Unable to convert EQ opcode 0x2ebd to an Application opcode.
6825 [12.08. - 01:36:33] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x2ebd) Size=0]
6825 [12.08. - 01:36:33] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x2ebd) Size=0]
6825 [12.08. - 01:36:44] [WORLD__CLIENT_TRACE] [OpCode OP_EnterWorld (0x1340) Size=72]
6825 [12.08. - 01:36:44] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x00ff
6825 [12.08. - 01:36:44] [NET__APP_TRACE] Queueing acked packet with opcode 0x192e (OP_MOTD) and length 403
6825 [12.08. - 01:36:44] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010d
6825 [12.08. - 01:36:44] [NET__APP_TRACE] Queueing acked packet with opcode 0x26c4 (OP_SetChatServer) and length 58
6825 [12.08. - 01:36:44] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010e
6825 [12.08. - 01:36:44] [NET__APP_TRACE] Queueing acked packet with opcode 0x1c20 (OP_SetChatServer2) and length 58
[Debug] [ZONE__WORLD_TRACE] Got 0x0031 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0008 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0006 from world:
6825 [12.08. - 01:36:45] [WORLD__CLIENTLIST] ClientList[0x08152540]::FindByAccountID(0x2) iterator.GetData()[0x8173890]
6825 [12.08. - 01:36:45] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010f
6825 [12.08. - 01:36:45] [NET__APP_TRACE] Queueing acked packet with opcode 0x13da (OP_ZoneServerInfo) and length 130

[trevius]

I pulled some more opcodes from the SEQ source. I didn't get them all yet, but from what I can tell, most (or maybe all) of these seem good so far:

#world packets
#Required to reach Char Select:
OP_SendLoginInfo=0x6c3c			#SEQ 12/04/08
OP_ApproveWorld=0x7FC0			#SEQ 12/04/08
OP_LogServer=0x129A			#SEQ 12/04/08
OP_SendCharInfo=0x6040			#SEQ 12/04/08
OP_ExpansionInfo=0x0A1B			#SEQ 12/04/08
OP_GuildsList=0x04FB			#SEQ 12/04/08
OP_EnterWorld=0x1340			#SEQ 12/04/08
OP_PostEnterWorld=0x1AEE		#SEQ 12/04/08
OP_SendSpellChecksum=0x7A9E		#SEQ 12/04/08
OP_World_Client_CRC1=0x3795		#SEQ 12/04/08
OP_World_Client_CRC2=0x45F9		#SEQ 12/04/08

#Character Select Related:
OP_DeleteCharacter=0x789F		#SEQ 12/04/08 0x26C9
OP_CharacterCreate=0x7E32		#SEQ 12/04/08 0x6160
OP_RandomNameGenerator=0x23D4		#SEQ 12/04/08 0x4849
OP_ApproveName=0x3EA6			#SEQ 12/04/08 0x413F

OP_MOTD=0x5711				#SEQ 12/04/08 0x192E
OP_SetChatServer=0x71B8			#SEQ 12/04/08 0x26C4
OP_SetChatServer2=0x32CC		#SEQ 12/04/08 0x1C20
OP_ZoneServerInfo=0x18B1		#SEQ 12/04/08 0x13DA
OP_WorldComplete=0x2486			#SEQ 12/04/08 0x3331 

#Reasons for Disconnect:
OP_ZoneUnavail=0x0264			#SEQ 12/04/08  0x407C
OP_WorldClientReady=0x3854		#SEQ 12/04/08 0x5E99
OP_ObfuscatorInfo=0x7930		#NEW FROM SEQ 12/04/08

OP_UserCompInfo=0x02a5			#NEW FROM SEQ 12/04/08
#OP_SendExeChecksum=0x1CB3		#SEQ 12/04/08
#OP_SendBaseDataChecksum=0x679D		#SEQ 12/04/08
OP_SendSkillCapsChecksum=0x45F9		#SEQ 12/04/08 0x21C7

#Zone in opcodes
OP_ZoneEntry=0x737E			#SEQ 12/04/08 0x7213
OP_AckPacket=0x4D38			#SEQ 12/04/08 0x7752
OP_NewZone=0x5D22 			#SEQ 12/04/08 0x0ADC -- From SEQ Forums after the patch  
OP_ReqClientSpawn=0x45D2 		#SEQ 12/04/08 0x0322
OP_ZoneSpawns=0x5AF2 			#SEQ 12/04/08 0x1900
OP_CharInventory=0x08A3 		#SEQ 12/04/08 0x5394 -- OP_ItemPlayerPacket
OP_SetServerFilter=0x7038 		#SEQ 12/04/08 0x6563
OP_LockoutTimerInfo=0x062c 		#SEQ 12/04/08 0x7f63 -- OP_Lockouts
OP_SendZonepoints=0x2992 		#SEQ 12/04/08 0x1932
OP_SpawnDoor=0x68C8 			#SEQ 12/04/08 0x1890
OP_ReqNewZone=0x5417 			#SEQ 12/04/08 0x7ac5
OP_PlayerProfile=0x0FEB 		#SEQ 12/04/08 0x6022
OP_TimeOfDay=0x7274 			#SEQ 12/04/08 0x0175 -- From SEQ Forums after the patch
OP_LevelUpdate=0x1036 			#SEQ 12/04/08 0x6A99
OP_Stamina=0x45E2 			#SEQ 12/04/08 0x82D7

At this point, it looks like I need to resolve a struct issue with ClientZoneEntry to progress further forward. I have tried variations of structures, but none seem to work yet. I am starting to think that the error I am getting is from the player profile structure being wrong and not the structure for getting the player's first name from ClientZoneEntry. I will go through the player profile structure next and compare them. But, if my logs are correct, it looks like alot of the structs we currently have are already correct. Here are my most recent logs (I marked in RED where I think the current issue is):

13296 [12.08. - 04:08:47] [WORLD__CLIENT_TRACE] [OpCode OP_AckPacket (0x4d38) Size=4]
13296 [12.08. - 04:08:47] Unable to convert EQ opcode 0x2ebd to an Application opcode.
13296 [12.08. - 04:08:47] [WORLD__CLIENT_TRACE] [OpCode OP_Unknown (0x2ebd) Size=0]
13296 [12.08. - 04:08:47] [WORLD__CLIENT_ERR] [OpCode OP_Unknown (0x2ebd) Size=0]
13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] [OpCode OP_EnterWorld (0x1340) Size=72]
13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x00ff
13296 [12.08. - 04:08:56] [NET__APP_TRACE] Queueing acked packet with opcode 0x5711 (OP_MOTD) and length 403
13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010d
13296 [12.08. - 04:08:56] [NET__APP_TRACE] Queueing acked packet with opcode 0x71b8 (OP_SetChatServer) and length 58
13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010e
13296 [12.08. - 04:08:56] [NET__APP_TRACE] Queueing acked packet with opcode 0x32cc (OP_SetChatServer2) and length 58
13296 [12.08. - 04:08:56] [WORLD__CLIENTLIST] ClientList[0x08152540]::FindByAccountID(0x2) iterator.GetData()[0x81746d8]13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010f
13296 [12.08. - 04:08:56] [NET__APP_TRACE] Queueing acked packet with opcode 0x18b1 (OP_ZoneServerInfo) and length 130
[ProtoOpCode 0x0015 Size=2]
[ProtoOpCode 0x0009 Size=4]
13296 [12.08. - 04:08:56] [WORLD__CLIENT_TRACE] [OpCode OP_WorldComplete (0x2486) Size=0]
[Debug] [ZONE__WORLD_TRACE] Got 0x0031 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0008 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0006 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0027 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0024 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x200e from world:
[Debug] [NET__NET_TRACE] 192.168.1.101:4185: Sending OP_SessionResponse: session 547790791, maxlen=512, key=0x11223344, compressed? yes, encoded? no
[ProtoOpCode 0x0009 Size=8]
[ProtoOpCode 0x0009 Size=72]
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode 0x4d38 did not match expected 0x2792
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode 0x4d38 did not match expected 0x2ec9
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode 0x4d38 did not match expected 0x4dd0
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode 0x4d38 did not match expected 0x7213
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode 0x4d38 did not match expected 0x6c3c
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4185: First opcode matched 0x737e and length matched 68
[Debug] [CLIENT__NET_IN_TRACE] No name: Dispatch opcode: [OpCode OP_AckPacket (0x4d38) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] No name: [OpCode OP_AckPacket (0x4d38) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] No name: Dispatch opcode: [OpCode OP_ZoneEntry (0x737e) Size=68]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] No name: [OpCode OP_ZoneEntry (0x737e) Size=68]
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0xfeb (OP_PlayerProfile) and length 23431
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x737e (OP_ZoneEntry) and length 900
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x7274 (OP_TimeOfDay) and length 8
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x5639 (OP_TributeUpdate) and length 48
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x4665 (OP_TributeTimer) and length 4
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x8a3 (OP_CharInventory) and length 4
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x5ef7 (OP_TaskDescription) and length 325
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 72
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x76a2 (OP_CompletedTasks) and length 60
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x254d (OP_Weather) and length 12
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x3cdc (OP_LogoutReply) and length 0

[trevius]

Hmm, I guess the section in red in the logs above aren't the issue. That seems to be normal when I compare it to these logs from a Titanium login that works:

13958 [12.08. - 04:33:25] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0103
13958 [12.08. - 04:33:25] [NET__APP_TRACE] Queueing acked packet with opcode 0x4ec (OP_ExpansionInfo) and length 4
13958 [12.08. - 04:33:25] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x0102
13958 [12.08. - 04:33:25] [NET__APP_TRACE] Queueing acked packet with opcode 0x4513 (OP_SendCharInfo) and length 1704
13958 [12.08. - 04:33:32] [WORLD__CLIENT_TRACE] [OpCode OP_ApproveWorld (0x3c25) Size=272]
13958 [12.08. - 04:33:33] [WORLD__CLIENT_TRACE] [OpCode OP_World_Client_CRC1 (0x5072) Size=2056]
13958 [12.08. - 04:33:33] [WORLD__CLIENT_TRACE] [OpCode OP_World_Client_CRC2 (0x5b18) Size=2056]
[ProtoOpCode 0x0009 Size=8]
13958 [12.08. - 04:34:03] [NET__NET_CREATE_HEX] 1969-12-31 18:00:03.000000 [ProtoOpCode 0x0009 Size=4]
13958 [12.08. - 04:34:03] [WORLD__CLIENT_TRACE] [OpCode OP_AckPacket (0x7752) Size=4]
13958 [12.08. - 04:34:03] [WORLD__CLIENT_TRACE] [OpCode OP_WorldClientReady (0x5e99) Size=0]
13958 [12.08. - 04:34:42] [WORLD__CLIENT_TRACE] [OpCode OP_EnterWorld (0x7cba) Size=72]
13958 [12.08. - 04:34:42] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x00ff
13958 [12.08. - 04:34:42] [NET__APP_TRACE] Queueing acked packet with opcode 0x24d (OP_MOTD) and length 403
13958 [12.08. - 04:34:42] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010d
13958 [12.08. - 04:34:42] [NET__APP_TRACE] Queueing acked packet with opcode 0xd7 (OP_SetChatServer) and length 58
13958 [12.08. - 04:34:42] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010e
13958 [12.08. - 04:34:42] [NET__APP_TRACE] Queueing acked packet with opcode 0x6536 (OP_SetChatServer2) and length 58
[Debug] [ZONE__WORLD_TRACE] Got 0x0031 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0008 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0006 from world:
13958 [12.08. - 04:34:42] [WORLD__CLIENTLIST] ClientList[0x08152540]::FindByAccountID(0x2) iterator.GetData()[0x8173900]13958 [12.08. - 04:34:42] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010f
13958 [12.08. - 04:34:42] [NET__APP_TRACE] Queueing acked packet with opcode 0x61b6 (OP_ZoneServerInfo) and length 130
[ProtoOpCode 0x0015 Size=2]
[ProtoOpCode 0x0009 Size=4]
13958 [12.08. - 04:34:43] [WORLD__CLIENT_TRACE] [OpCode OP_WorldComplete (0x509d) Size=0]
[Debug] [ZONE__WORLD_TRACE] Got 0x0027 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x0024 from world:
[Debug] [ZONE__WORLD_TRACE] Got 0x200e from world:
[Debug] [NET__NET_TRACE] 192.168.1.101:4296: Sending OP_SessionResponse: session 767659547, maxlen=512, key=0x11223344, compressed? yes, encoded? no
[Debug] [NET__NET_CREATE_HEX] 1969-12-31 18:04:16.000000 [ProtoOpCode 0x0009 Size=8]
[ProtoOpCode 0x0009 Size=72]
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4296: First opcode 0x7752 did not match expected 0x2792
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4296: First opcode 0x7213 did not match expected 0x2ec9
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4296: First opcode 0x7752 did not match expected 0x4dd0
[Debug] [NET__IDENT_TRACE] 192.168.1.101:4296: First opcode matched 0x7213 and length matched 68
[Debug] [CLIENT__NET_IN_TRACE] No name: Dispatch opcode: [OpCode OP_AckPacket (0x7752) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] No name: [OpCode OP_AckPacket (0x7752) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] No name: Dispatch opcode: [OpCode OP_ZoneEntry (0x7213) Size=68]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] No name: [OpCode OP_ZoneEntry (0x7213) Size=68]
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x75df (OP_PlayerProfile) and length 19592
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x7213 (OP_ZoneEntry) and length 385
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x1580 (OP_TimeOfDay) and length 8
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x5639 (OP_TributeUpdate) and length 48
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x4665 (OP_TributeTimer) and length 4
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x5394 (OP_CharInventory) and length 78352
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x5ef7 (OP_TaskDescription) and length 325
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 72
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x682d (OP_TaskActivity) and length 28
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x76a2 (OP_CompletedTasks) and length 60
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x254d (OP_Weather) and length 12
[ProtoOpCode 0x0015 Size=2]
[ProtoOpCode 0x0009 Size=8]
[Debug] [CLIENT__NET_IN_TRACE] Trevazar: Dispatch opcode: [OpCode OP_AckPacket (0x7752) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] Trevazar: [OpCode OP_AckPacket (0x7752) Size=4]
[Debug] [CLIENT__NET_IN_TRACE] Trevazar: Dispatch opcode: [OpCode OP_ReqNewZone (0x7ac5) Size=0]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] Trevazar: [OpCode OP_ReqNewZone (0x7ac5) Size=0]
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x920 (OP_NewZone) and length 700
[Debug] [NET__APP_TRACE] Queueing acked packet with opcode 0x2a28 (OP_CustomTitles) and length 4
[ProtoOpCode 0x0015 Size=2]
[ProtoOpCode 0x0009 Size=4]
[ProtoOpCode 0x0009 Size=4]
[Debug] [CLIENT__NET_IN_TRACE] Trevazar: Dispatch opcode: [OpCode OP_SendAATable (0x367d) Size=0]
[Debug] [CLIENT__NET_IN_TRACE] [CLIENT__NET_IN_TRACE] Trevazar: [OpCode OP_SendAATable (0x367d) Size=0]

The previous logs are all grepping on "0x" to catch all opcodes. Here are some more detailed logs of exactly when the failure happens with the SoF client:

14299 [12.08. - 04:45:48] [WORLD__CLIENTLIST] ClientList[0x08152540]::FindByAccountID(0x2) iterator.GetData()[0x8173520]14299 [12.08. - 04:45:48] [WORLD__CLIENT] trevadmin: Sending client to zone load (184) at 192.168.1.102:7503
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] trevadmin: Sending EQApplicationPacket OpCode 0x010f
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] [OpCode OP_ZoneServerInfo Size=130]
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0000: 31 39 32 2e 31 36 38 2e - 31 2e 31 30 32 00 00 00  | 192.168.1.102...
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0016: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0032: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0048: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0064: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0080: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0096: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0112: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] 0128: 4f 1d                   -                          | O.
14299 [12.08. - 04:45:48] [NET__APP_TRACE] Queueing acked packet with opcode 0x18b1 (OP_ZoneServerInfo) and length 130
14299 [12.08. - 04:45:48] [NET__APP_TRACE] 192.168.1.101:4316: Pushing sequenced packet 202 of length 134. Base Seq is 202.
14299 [12.08. - 04:45:48] [NET__NET_COMBINE] 192.168.1.101:4316: Starting combined packet with seq packet 202 of len 13414299 [12.08. - 04:45:48] [NET__NET_COMBINE] 192.168.1.101:4316: Final combined packet not full, len 134
14299 [12.08. - 04:45:48] [NET__NET_CREATE] 192.168.1.101:4316: Extracting combined packet of length 4
14299 [12.08. - 04:45:48] [NET__NET_CREATE_HEX] 2030-10-13 02:40:48.2053207653 [216.66.23.8:0->0.0.0.2:64000]
[ProtoOpCode 0x0015 Size=2]

14299 [12.08. - 04:45:48] [NET__NET_CREATE_HEX] 0000: 00 ca                   -                          | ..
14299 [12.08. - 04:45:48] [NET__NET_ACKS] 192.168.1.101:4316: Received an ack with no window advancement (seq 202).
14299 [12.08. - 04:45:48] [NET__NET_CREATE] 192.168.1.101:4316: Extracting combined packet of length 6
14299 [12.08. - 04:45:48] [NET__NET_CREATE_HEX] 1974-04-21 20:19:36.000000 [216.66.23.8:17720->56.69.172.183:47020]
[ProtoOpCode 0x0009 Size=4]

14299 [12.08. - 04:45:48] [NET__NET_CREATE_HEX] 0000: 00 19 86 24             -                          | ...$
14299 [12.08. - 04:45:48] [NET__NET_ACKS] 192.168.1.101:4316: Set Next Ack To Send to 25
14299 [12.08. - 04:45:48] [NET__APP_CREATE] 192.168.1.101:4316: Creating new application packet, length 2
14299 [12.08. - 04:45:48] [NET__APP_CREATE_HEX] 0000: 86 24                   -                          | .$
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] trevadmin: Recevied EQApplicationPacket
14299 [12.08. - 04:45:48] [WORLD__CLIENT_TRACE] [OpCode OP_WorldComplete (0x2486) Size=0]
14299 [12.08. - 04:45:48] [NET__DEBUG] 192.168.1.101:4316: Stream requested to Close(), but there is pending data, waiting for it.
14299 [12.08. - 04:45:48] [NET__NET_TRACE] 192.168.1.101:4316: Changing state from 0 to 1
14299 [12.08. - 04:45:48] [WORLD__CLIENT] trevadmin: Client disconnected (not active in process)
14299 [12.08. - 04:45:48] [WORLD__CLIENTLIST] Removing client from 192.168.1.101:4316
14299 [12.08. - 04:45:48] [NET__DEBUG] 192.168.1.101:4316: Stream requested to Close(), but there is pending data, waiting for it.

It looks like it happens right after the OP_WorldComplete comes in, so maybe that has something to do with it.

[John Adams]

Wow, nice work trevius. I can't help in the slightest, but I make a decent cheerleader.

Go Go T!