Crashes / Disconnects

[LethalEncounter]

Both of those were the encryption getting thrown off. You can tell because the server starts receiving all kinds of wierd packets with corrupt data until the server sends the client something that it doesn't expect and it dies.

[John Adams]

I'm starting to suspect my ISP, because at varying times, visiting these forums is horribly slow. I must be just me, because no one else has complained
Maybe I'm getting clipped, which would explain why Scatman gets bumped same time I do sometimes.

[John Adams]

I am seeing this Timeout up!, state=0 a LOT more lately now that I've been paying attention. Not that any players ever bother to post that they are having problems ~grumble~ so I am really just guessing, but whenever I see that message, I have been disconnected. The fact the player does not immediately log back on though leaves me thinking it could be an abnormal disconnect maybe from their side. Who knows.
I will start keeping track of what zones this Timeout up! happens in, in case it could be related to our data.

[John Adams]

Re-opening this bug, and I will try to get more detailed information about some of the crashes I am seeing lately. The console does not appear to be showing anything abnormal, so I hope this is enough. It never seems to be the exact same thing that is crashing, almost appears random... but the console lacks lots of detailed debug info, so I cannot say for sure.

Code: Select all

Left Grid 164927960 and Entered Grid 857760680
Left Grid 857760680 and Entered Grid 3058621861
Left Grid 3058621861 and Entered Grid 857760680
   0: 01 00 00 00                                        | ....
   0: 01 00 0B 00 32 20 35 30 - 20 31 38 20 2D 31 32     | ....2 50 18 -12
Received spawn command.
Parms: 2 50 18 -12
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 01 00 0B 00 33 20 37 30 - 20 31 38 20 2D 31 32     | ....3 70 18 -12
Received spawn command.
Parms: 3 70 18 -12
   0: 01 00 0B 00 33 20 34 30 - 20 31 38 20 2D 31 32     | ....3 40 18 -12
Received spawn command.
Parms: 3 40 18 -12
   0: 01 00 0B 00 34 20 34 30 - 20 31 38 20 2D 31 32     | ....4 40 18 -12
Received spawn command.
Parms: 4 40 18 -12
   0: CB 01 06 00 73 65 61 72 - 63 68                    | ....search
Unhandled command: guild
   0: 01 00 0D 00 36 36 36 20 - 33 33 20 31 37 20 2D 31  | ....666 33 17 -1
  16: 30                                                 | 0
   0: 01 00 0C 00 36 36 20 33 - 33 20 31 37 20 2D 31 30  | ....66 33 17 -10
   0: 01 00 0B 00 34 20 33 33 - 20 31 37 20 2D 31 30     | ....4 33 17 -10
Received spawn command.
Parms: 4 33 17 -10
   0: 01 00 0B 00 35 20 35 33 - 20 31 37 20 2D 31 30     | ....5 53 17 -10
[Status] Using database 'eq2live' at mysql.visionsmusicgroup.local
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.0 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..
[Status]        Connected to Update Server: eq2emulator.net:9102
[Status]        Checking for updates.
[Status]        Server is already up-to-date.

I am not sure, but I think those numbers are the player moving inventory around? This is the first time I've seen this. Normally, it's only the Left Grid action, or even a simple /who all (where "all" is what I see in the console, then boom - crash.
Since I am running on the VM now, the server does restart ok, so unless I am watching it closely, I cannot see it actually happen. After rebuilding my dev machine today (don't ask) I'll see if I can get in-game and try and find something repeatable.

[LethalEncounter]

Those are the packet dumps of the commands that people are using. The first two bytes (01 00) at the beginning are the handler id for the command. In this case handler 0x0001 (or 1) refers to the spawn command. The next two bytes are the size of the remaining parameter data (11 in this case). The command issued right before the crash was: /spawn 5 53 17 -10
I'll do some testing, as there might be a bug in ths spawn code.

[John Adams]

Here's another crash console. I was watching a player do what I interpret as clicking like mad around everywhere due to the literal hundreds of "clearallqueuedabilities" I saw flying by the screen (which caught my eye). Soon after, I saw this weird thing about destroytotem which I don't think I've seen before. And finally the gem; the player zoned, and the server crashed.

Code: Select all

Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
Unknown command in OP_EntityVerbsVerbMsg: destroy totem
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
Unknown command in OP_EntityVerbsVerbMsg: destroy totem
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
Unknown command in OP_EntityVerbsVerbMsg: destroy totem
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
Unknown command in OP_EntityVerbsVerbMsg: destroy totem
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
Zone access check for QueensColony
AddAuth: 3705 Key: 1227242609
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
OP_ReadyToZone: Player XXXXXX zoning to QueensColony
3264352 New client from ip: xxx.xxx.xxx.xxx port: 2375
ZoneAuth: Access Key, 1227242609, Character Name, XXXXXX, Account ID, 3705, TimeStamp, 1227242609
OP_Unknown Received 0x0026
   0: 01 00 00 00 C8 43                                  | .....C
Zone: Removing client from ip:xxx.xxx.xxx.xxx port:2375
[Status] Using database 'eq2live' at mysql
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.0 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..

Right between Removing client and Using database is my auto-restart.

[John Adams]

Also, after this player crashed out, I saw a couple of Got Signal 11's so I tried to connect to my own server, and the LoginServer reported I had no characters.
I've seen this behavior before too, where my server gets no business for hours on end, and when I check the site server stats, it says TessEQ2 is offline, but it is not. Usually this happens (I think) when my loving ISP decides to nuke my IP and give me a new one... in this case, I guess it's understandable heh. But in the previous case, I think that's still a legit issue. I wish I had more to go on than bad memory.

[LethalEncounter]

I think this is related to the items crash bug. It was caused by a bug in the code and happened if the player had an empty bag when they logged in. This should be fixed in the next update.

[John Adams]

This could also be another missing item problem, but just in case, here's another console crash.

Code: Select all

Left Grid 2679351936 and Entered Grid 1704840540
Left Grid 1704840540 and Entered Grid 2679351936
OP_SatMsg Received 0x00aa
Zone: Removing client from ip:xxx.xxx.xxx.xxx port:55981
Removing connection
Shutting Down Zone 'NorthQeynos'
Delete char request: 3586 1187
Delete char request: 3586 1187
Delete char request: 3586 1182
Delete char request: 3586 1182
AddAuth: 3215 Key: 1227342805
99378142 New client from ip: xxx.xxx.xxx.xxx port: 3367
ZoneAuth: Access Key, 1227342805, Character Name, XXXXXX, Account ID, 3215, TimeStamp, 1227342805
Loading new Zone 'SouthQeynos'
Loaded 0 NPC(s), 0 Object(s), 0 Widget(s), 0 Sign(s).
OP_ChatFiltersMsg Received 0x013d
   0: 0D 00 FF FF FF FF FF 01 - 00 00 00 80 FF FF 0B 01  | ................
OP_ChatFiltersMsg Received 0x013d
   0: 0D 00 FF FF FF FF FF FF - FF FF FF FF FF FF 0B 01  | ................
OP_Unknown Received 0x0026
   0: 01 00 00 00 FA 43                                  | .....C
[Status] Using database 'eq2live' at mysql
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.0 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..
[Status]        Connected to Update Server: eq2emulator.net:9102
[Status]        Checking for updates.

In this one you had one user earlier just moving about, then logged off. Someone else came by and tried deleting their toons (looks like 2 tries each?)
The next player to login crashed immediately. South Qeynos, fwiw, has 0 spawns... so maybe it isn't data this time, but that item thing. If there's a quick fix, I'd be interested. Delete all player items? Or give everyone something?

[LethalEncounter]

Until the fix is uploaded, just ensure that if your starting items has a bag in it, that you also give them another item to go inside of it. I also found and fixed a bug with connections that was crashing the server. It will also be checked in soon.

[John Adams]

I decided to run the latest SVN on the public server (we'll just wait for the mentioned bugs to get fixed for quests/move_spawn). If this items fix is in 164, then maybe this is something different.

Code: Select all

Loading new Zone 'Neriak'
Loaded 0 NPC(s), 0 Object(s), 0 Widget(s), 0 Sign(s).
OP_Unknown Received 0x0026
   0: 01 00 00 00 C8 43                                  | .....C
OP_Unknown Received 0x00b2
   0: 00 00                                              | ..
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: 23 00 01 00 31                                     | #...1
   0: D4 00 06 00 6D 61 6E 74 - 6C 65                    | ....mantle
   0: 19 00 04 00 31 31 37 39                            | ....1179
Left Grid 4294967295 and Entered Grid 4002538494
   0: 3A 00 04 00 38 3A 33 30                            | :...8:30
   0: 19 00 04 00 31 31 37 39                            | ....1179
OP_SatMsg Received 0x00ab
   0: 18 00 0F 00 65 71 75 69 - 70 20 31 37 20 2D 31 20  | ....equip 17 -1
  16: 30 20 30                                           | 0 0
   0: 7C 01 00 00                                        | |...
Unhandled command: afk
   0: 19 00 01 00 38                                     | ....8
Zone: Removing client from ip:xxx.xxx.xxx.xxx port:1326
   0: 18 00 0C 00 6D 6F 76 65 - 20 38 20 31 20 30 20 30  | ....move 8 1 0 0
command: inventory
   0: 21 00 0B 00 69 6E 76 65 - 6E 74 6F 72 79 20 38     | !...inventory 8
   0: 19 00 03 00 34 39 31                               | ....491
Removing connection
   0: 18 00 16 00 75 6E 65 71 - 75 69 70 20 34 20 32 38  | ....unequip 4 28
  16: 37 38 38 20 31 39 20 30 - 20 30                    | 788 19 0 0
   0: 18 00 0F 00 65 71 75 69 - 70 20 31 38 20 2D 31 20  | ....equip 18 -1
  16: 30 20 30                                           | 0 0
OP_SatMsg Received 0x00ab
Delete char request: 3723 1189
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: 07 00 37 00 62 62 6C 2C - 20 68 61 76 65 20 66 75  | ..7.bbl, have fu
  16: 6E 2E 20 72 65 70 6F 72 - 74 20 61 6E 79 20 62 75  | n. report any bu
  32: 67 73 20 74 6F 20 74 68 - 65 20 66 6F 72 75 6D 73  | gs to the forums
  48: 2C 20 70 6C 65 61 73 65 - 20 3A 29                 | , please :)
OP_SatMsg Received 0x00ab
Zone: Removing client from ip:192.168.1.100 port:4401
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
Removing connection
Shutting Down Zone 'Neriak'
OP_ClientIdleEndMsg Received 0x017b
   0: 00                                                 | .
OP_BeginTrackingMsg Received 0x016d
   0: 99                                                 | .
[Status] Using database 'eq2live' at mysql
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.0 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..
[Status]        Connected to Update Server: eq2emulator.net:9102
[Status]        Checking for updates.
[Status]        Server is already up-to-date.
[Status] Loading opcodes..
[Status] Loading structs..
[Status] Loading command list..
[Status] Loaded 109 entity command lists.
[Status] Loaded 2031 NPC(s).
[Status] Loaded 376 Object(s).
[Status] Loaded 196 Widget(s).
[Status] Loaded 402 Sign(s).
[Status] Loaded global variables list..
[Status] Loaded visual states list..
[Status] Loading World Time..
[Status] Loading items.. (this might take a few minutes)
[Status]        Loaded 40 Bag(s)
[Status]        Loaded 76 Food(s)
[Status]        Loaded 3324 Weapon(s)
[Status]        Loaded 7609 Armor/Shield Piece(s)
[Status]        Loaded 0 Skill Item(s)
[Status]        Loaded 1009 Regular Items
[Status] Loading spells..
[Status]        Loaded 3665 Spell(s)
[Status] Loading LUA spells..
[Status]        Loaded 23 LUA Spell(s)
[Status] Loading factions..
[Status]        Loaded 51 Factions
[Status] Loading skills..
[Status]        Loaded 129 Skills
[Status] Loading loot data..
[Status]        Loaded 0 loot tables.
[Status]        Loaded 0 loot drops.
[Status]        Loaded 0 spawn loot lists.
[Status] Loading Quests..
[Status]        Loaded 46 Quest(s)
[Status] Loading Merchant Information..
[Status]        Loaded 2 Merchant List(s)
[Status]        Loaded 1 Merchant Multiplier(s)
[Status] Loading Spawn Script Information..
[Status] Loading EQ time of day..
Breaking your databases!!
Starting factory Reader
Starting factory Writer
World server listening on: tesseq.servegame.com:9200
World server listening on: 192.168.1.33:9200
Starting static zones...
Connected to LoginServer: eq2emulator.net:9100
69.60.121.221:9100: TCPConnection::RecvData(): Error: 10054
Connected to LoginServer: eq2emulator.net:9100

What you see here is me logged in with 2 clients, one on each PC, and a 3rd player testing items. A 4th player logs in to Neriak, then disconnects and deletes the toon. While I am saying goodbye to the player in my zone, I did a /camp, and on my second PC, did a /exit. There is a zone shutdown for Neriak. Right after that, world restarted.
Edit: I included the entire server startup, because I just noticed there was an error connecting to LS. This is suspicious only in that I notice crashes like this sometimes when I come back from being disconnected from the LS for a period of time. I always thought it was me getting a new IP possibly... but maybe not?

[John Adams]

Well shit... 2nd crash in an hour after putting up the new server (SVN compile). This time it looked like a player was just wandering around, and crashed.

Code: Select all

Unhandled command: clearallqueuedabilities
OP_DialogCloseMsg Received 0x0067
   0: E9 9A 26 00                                        | ..&.
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 31                                     | %...1
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 31                                     | %...1
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
Left Grid 924281492 and Entered Grid 771354606
Left Grid 771354606 and Entered Grid 924281492
Left Grid 924281492 and Entered Grid 771354606
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 31                                     | %...1
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
   0: 25 00 01 00 30                                     | %...0
   0: CD 01 00 00                                        | ....
Unhandled command: clearallqueuedabilities
OP_BeginTrackingMsg Received 0x0175
   0: 00                                                 | .
[Status] Using database 'eq2live' at mysql

This very well could be quests related, as the two players so far have tried the Murrar Shar quests. If that's the case, you may already know about it. I don't know how to globally disable questing until this is fixed, though.
Bad week to have a holiday, yes indeed. Oh well.

[LethalEncounter]

lol ya, hmm I'll open my server up and see if I can catch the crash. If it doesnt happen tonight with my DB I can source a copy of your DB and see if it is somehow data related.

[John Adams]

It's crashing nearly every login from what I can see. If your server is open, I'll log in there and try bringing it down. I just cannot tell by the console what the players are doing to replicate it.

[LethalEncounter]

Yup it is open and I'm on it.