Page 19 of 24
Re: Crashes / Disconnects
Posted: Tue Mar 10, 2009 2:25 pm
by LethalEncounter
John Adams wrote:Mkay... interesting. For days, I ran Debug code with remote debugger attached, not one crash through all the work Scatman has done and players testing items, zoning all around. I put the release binary online, and within 2 hours, it crashes. No idea what was happening, but here's the console for the last connection (this same user seemed to be dropped a few times doing the same thing)
Code: Select all
AddAuth: 3842 Key: 1236653247
3383687 New client from ip: xxx.xxx.xxx.xxx port: 54016
ZoneAuth: Access Key, 1236653247, Character Name, Useuchu, Account ID, xxxx, TimeStamp, 1236653247
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 96 43 | .....C
OP_Unknown Received 0x00b2
0: 00 00 | ..
0: CC 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: 23 00 01 00 31 | #...1
0: CC 01 00 00 | ....
Unhandled command: clearallqueuedabilities
OP_ChatFiltersMsg Received 0x013d
0: 0D 00 FF FF FF FF FF FF - FF FF FF FF FF FF 0B 01 | ................
0: 01 00 07 00 64 65 74 61 - 69 6C 73 | ....details
Left Grid 4294967295 and Entered Grid 771354606
0: CC 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 01 00 07 00 64 65 74 61 - 69 6C 73 | ....details
OP_BeginTrackingMsg Received 0x0175
0: 3E | >
Zone: Removing client from ip:xxx.xxx.xxx.xxx port:54016
Removing connection
This is "unknwon"s IP, and there was some talk about a packet scanner he made, which I am still waiting for an explanation why it would be used on my server.
Hmm, I'll enable the new Mutex code on release and see if that solves the problem.
Re: Crashes / Disconnects
Posted: Tue Mar 10, 2009 4:17 pm
by John Adams
Scatman wrote:I tried doing "/spawn set faction 1" today and instantly got booted. I don't think World crashed but John will have to verify that.
I do not see a world restart today. Scat, that logview script I linked you should show you what the world is doing live. I'll move that into the editor's Admin section soon, promise.
Re: Crashes / Disconnects
Posted: Tue Mar 10, 2009 4:29 pm
by Scatman
Yah, I forgot the link
Meant to ask you for it again.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 10:35 am
by John Adams
Seeing around 2-3 crashes per day still. When I run in Debug, the server runs for a week without a single failure. Soon as I put it in Release, it will crash regularly again. Can't really debug things that way. Hopefully some things in this console output can give you a clue what may be happening... but to me, it looks like standard play - nothing special going on. Movement, spell casting, zones shutting down, etc.
Code: Select all
Shutting Down Zone 'Darklight'
0: 22 00 01 00 32 | "...2
0: 22 00 01 00 32 | "...2
0: 22 00 01 00 32 | "...2
0: 22 00 05 00 31 30 30 30 - 32 | "...10002
0: 22 00 06 00 31 30 30 30 - 30 32 | "...100002
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
Left Grid 4294967295 and Entered Grid 1698999948
Zone: Removing client from ip:71.120.238.196 port:2087
Removing connection
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
OP_Unknown Received 0x01d2
0: 00 00 00 FF FF FF FF 88 | ........
0: 55 00 00 00 | U...
OP_DialogCloseMsg Received 0x0067
0: 24 65 11 00 | $e..
[Status] Using database 'eq2live' at mysql
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.5 Developer Alpha
I am turning off Beta Heal and Beta Damage for now, in case those are causing problems.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 10:51 am
by LethalEncounter
I'll enable the Mutex code for the release build as well. That should explain the problem if it is a lock issue.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 11:02 am
by John Adams
I just compiled another debug, but I'll wait to try this code after you check it in. Maybe something will surface.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 6:24 pm
by John Adams
Er, LE?
I am getting possible deadlocks just running the new EXE (self compiled off SVN). I will try a clean and make again just in case. Got 3 of them before the code would continue loading, and it is verrrry slow...
Code: Select all
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.5 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..
[Status] Connected to Update Server: updates.eq2emulator.net:9103
[Status] Checking for updates.
[Status] Server is already up-to-date.
[Status] Loading opcodes..
[Status] Loading structs..
[Status] Loading command list..
[Status] Loaded 506 entity command lists.
[Status] Loaded 3907 NPC(s).
[Status] Loaded 627 Object(s).
[Status] Loaded 84 GroundSpawn(s).
[Status] Loaded 467 Widget(s).
Possible deadlock attempt by 'Spawn::MPacketData'!
Possible deadlock attempt by 'Spawn::MPacketData'!
Possible deadlock attempt by 'Spawn::MPacketData'!
[Status] Loaded 567 Sign(s).
[Status] Loading ground spawn items..
[Status] Loading loot data..
[Status] Loaded 4 loot tables.
[Status] Loaded 8 loot drops.
[Status] Loaded 4 spawn loot lists.
[Status] Loading Transporter Information..
[Status] Loaded 24 Teleporter(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 282 Bag(s)
[Status] Loaded 2072 Food(s)
[Status] Loaded 14064 Weapon(s)
[Status] Loaded 32761 Armor/Shield Piece(s)
[Status] Loaded 0 Skill Item(s)
[Status] Loaded 9906 Regular Items
[Status] Loading spells..
Possible deadlock attempt by 'Spell::MSpellInfo'!
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 6:30 pm
by John Adams
k after a Clean and Rebuild Project, I got passed the first set of deadlocks, but it hit the Spells load and is deadlocking again. Or, just saying that there is a possible deadlock anyway. I'll let it load all the way to see how it works once running completely.
Code: Select all
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.5 Developer Alpha
[Status] ./LoginServer.ini read.
[Status] Connecting to Update Server..
[Status] Connected to Update Server: updates.eq2emulator.net:9103
[Status] Checking for updates.
[Status] Server is already up-to-date.
[Status] Loading opcodes..
[Status] Loading structs..
[Status] Loading command list..
[Status] Loaded 506 entity command lists.
[Status] Loaded 3907 NPC(s).
[Status] Loaded 627 Object(s).
[Status] Loaded 84 GroundSpawn(s).
[Status] Loaded 467 Widget(s).
[Status] Loaded 567 Sign(s).
[Status] Loading ground spawn items..
[Status] Loading loot data..
[Status] Loaded 4 loot tables.
[Status] Loaded 8 loot drops.
[Status] Loaded 4 spawn loot lists.
[Status] Loading Transporter Information..
[Status] Loaded 24 Teleporter(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 282 Bag(s)
[Status] Loaded 2072 Food(s)
[Status] Loaded 14064 Weapon(s)
[Status] Loaded 32761 Armor/Shield Piece(s)
[Status] Loaded 0 Skill Item(s)
[Status] Loaded 9906 Regular Items
[Status] Loading spells..
Possible deadlock attempt by 'Spell::MSpellInfo'!
Possible deadlock attempt by 'Spell::MSpellInfo'!
Possible deadlock attempt by 'Spell::MSpellInfo'!
Possible deadlock attempt by 'Spell::MSpellInfo'!
Possible deadlock attempt by 'Spell::MSpellInfo'!
Possible deadlock attempt by 'Spell::MSpellInfo'!
If you don't respond tonight, I'll just revert to an older version for the night.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 7:14 pm
by LethalEncounter
hmm wtf, there must be something else going on there because there is not way that MSpellInfo could be deadlocked. I'll try to figure it out tomorrow :/
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 7:18 pm
by John Adams
Heh, ok. Yeah I thought that was pretty damn strange... considering otherwise, the world loads and starts with no problems.
Btw, I just watched the world die. unfortunately, no debug or mutex code running, so another dud... maybe we'll get fortunate and alfa or xanibunib will come tell us what they experienced.
But here's what I saw... player zoned, moved, after excessive spell casting and movement... saw the zone crash:
Code: Select all
Unhandled command: clearallqueuedabilities
0: 22 00 05 00 31 30 30 30 - 30 | "...10000
0: 25 00 01 00 31 | %...1
0: 22 00 05 00 33 30 30 30 - 32 | "...30002
0: 22 00 05 00 33 30 30 30 - 36 | "...30006
0: 22 00 05 00 31 30 30 30 - 32 | "...10002
0: 22 00 05 00 33 30 30 30 - 32 | "...30002
0: 22 00 05 00 31 30 30 30 - 32 | "...10002
0: 22 00 05 00 33 30 30 30 - 36 | "...30006
0: 22 00 05 00 33 30 30 30 - 31 | "...30001
0: 22 00 05 00 33 30 30 30 - 36 | "...30006
0: 22 00 05 00 33 30 30 30 - 36 | "...30006
0: 29 00 03 00 61 6C 6C | )...all
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: 38 00 06 00 6F 63 68 61 - 69 6D | 8...ochaim
AddAuth: 1667 Key: 1237774479
OP_ReadyToZone: Player Xanibunib zoning to SourceEvil
2188461 New client from ip: 67.190.134.169 port: 61574
ZoneAuth: Access Key, 1237774479, Character Name, Xanibunib, Account ID, 1667, TimeStamp, 1237774479
OP_Unknown Received 0x0026
0: 01 00 66 66 31 44 | ..ff1D
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
Zone: Removing client from ip:67.190.134.169 port:61574
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
Left Grid 4294967295 and Entered Grid 3240910078
Error Processing SpawnLoop, shutting down zone...
Removing connection
Removing connection
[Status] Using database 'eq2live' at mysql
[Status] CURRENT_WORLD_VERSION:EQ2EMu 0.6.5 Developer Alpha
Boot both players, and a moment later, world restarted.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 7:19 pm
by LethalEncounter
bah nm, I found it. Was an issue with me not removing a #ifdef debug tag and when you were running it in release mode it was causing that issue. I'll upload the changes in a couple of minutes, but if you run in debug you should be fine also.
Re: Crashes / Disconnects
Posted: Sun Mar 22, 2009 7:21 pm
by John Adams
Woot. I knew you'd be too curious to let it go. hee hee. lucky me.
Thanks LE. I'll see if I can catch some of these oddball crashes this week.
Re: Crashes / Disconnects
Posted: Wed Mar 25, 2009 5:46 pm
by John Adams
Got that weird thing again where the world is "DOWN", but there is a zone loaded showing 12 clients connected.
12-clients.jpg
Xan might be able to shed some light on how to reproduce this, but I honestly cannot say it was his script/reload sequence, since we've seen this before. Real odd part, someone is still in the server, playing away. I see movement and spell casting going on, yet I cannot connect to it myself.
(the repeated Logging to is how many times the world has crashed today. :p)
Re: Crashes / Disconnects
Posted: Wed Mar 25, 2009 6:28 pm
by John Adams
Not sure why Tess showed offline. Maybe it was the loginserver offline a moment? Anyway. I am logged in now, 3 players online (including myself). 2 zones active. 14 clients connected. I'm thinking if I disconnnect now and reconnect immediately, I will see 15 clients connected in teh console.
We've seen this before. No idea how to reproduce it.
Re: Crashes / Disconnects
Posted: Sat Mar 28, 2009 6:10 pm
by John Adams
Not a crash, but something Scat and I seem to be able to reproduce - and it may just be a side effect of casting spells too fast before the other "tick" finishes.
Code: Select all
Left Grid 1246288135 and Entered Grid 771354606
0: 01 00 0F 00 73 65 74 20 - 73 68 6F 77 5F 6E 61 6D | ....set show_nam
16: 65 20 30 | e 0
0: 01 00 10 00 73 65 74 20 - 74 61 72 67 65 74 61 62 | ....set targetab
16: 6C 65 20 30 | le 0
Combined Packet!
Combined Packet!
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: 0C 00 4C 00 74 68 61 74 - 73 20 77 65 69 72 64 2C | ..L.thats weird,
16: 20 69 20 6B 6E 6F 77 20 - 79 6F 75 20 63 61 6E 20 | i know you can
32: 68 69 64 65 20 79 6F 75 - 72 20 6F 77 6E 20 68 6F | hide your own ho
48: 6F 64 2C 20 64 75 6E 6E - 6F 20 77 68 61 74 73 20 | od, dunno whats
64: 75 70 20 77 69 74 68 20 - 74 68 65 20 4E 50 43 73 | up with the NPCs
0: 03 00 02 00 38 30 | ....80
0: 22 00 04 00 33 30 30 30 | "...3000
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 22 00 04 00 33 30 30 30 | "...3000
Possible deadlock attempt by 'SpellProcess::MActiveSpells'!
0: 22 00 04 00 33 30 30 30 | "...3000
0: 29 00 03 00 61 6C 6C | )...all
Combined Packet!
Possible deadlock attempt by 'SpellProcess::MActiveSpells'!
0: 0C 00 12 00 77 65 20 6A - 75 73 74 20 64 65 61 64 | ....we just dead
16: 6C 6F 63 6B 65 64 | locked
0: 29 00 03 00 61 6C 6C | )...all
0: 0C 00 61 00 69 20 63 61 - 73 74 20 2F 75 73 65 61 | ..a.i cast /usea
16: 62 69 6C 69 74 79 20 33 - 30 30 30 2C 20 6F 6E 63 | bility 3000, onc
32: 65 20 6F 6E 20 6E 6F 20 - 74 61 72 67 65 74 2C 20 | e on no target,
48: 74 77 69 63 65 20 6F 6E - 20 6D 65 20 69 6E 20 71 | twice on me in q
64: 75 69 63 6B 20 73 75 63 - 63 65 73 73 69 6F 6E 20 | uick succession
80: 61 6E 64 20 6C 6F 63 6B - 65 64 20 74 68 65 20 77 | and locked the w
96: 6F 72 6C 64 2E | orld.
0: 0C 00 0F 00 63 61 6E 20 - 79 6F 75 20 74 72 79 20 | ....can you try
16: 69 74 3F | it?
0: 0C 00 10 00 74 72 79 20 - 2F 75 73 65 61 62 69 6C | ....try /useabil
16: 69 74 79 3F | ity?
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 22 00 04 00 33 30 30 30 | "...3000
Combined Packet!
0: 0C 00 0F 00 69 20 68 65 - 61 6C 65 64 20 6D 79 73 | ....i healed mys
16: 65 6C 66 | elf
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 22 00 05 00 33 30 30 30 - 30 | "...30000
0: 22 00 05 00 33 30 30 30 - 30 | "...30000
0: 0C 00 0A 00 79 65 61 68 - 2E 20 33 30 30 30 | ....yeah. 3000
0: 22 00 05 00 33 30 30 30 - 30 | "...30000
0: 25 00 01 00 31 | %...1
0: 22 00 05 00 33 30 30 30 - 30 | "...30000
0: 0C 00 12 00 64 6F 33 20 - 6F 66 20 74 68 65 6D 20 | ....do3 of them
16: 71 75 69 63 6B 2E | quick.
0: 0C 00 11 00 69 6D 20 61 - 74 74 61 63 6B 69 6E 67 | ....im attacking
16: 20 66 69 6E 65 | fine
0: 0C 00 02 00 6F 6B | ....ok
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 25 00 01 00 30 | %...0
0: CB 01 00 00 | ....
Unhandled command: clearallqueuedabilities
0: 22 00 04 00 33 30 30 30 | "...3000
0: 22 00 04 00 33 30 30 30 | "...3000
Combined Packet!
0: 29 00 03 00 61 6C 6C | )...all
0: 0C 00 04 00 68 6D 6D 2E | ....hmm.
Possible deadlock attempt by 'SpellProcess::MActiveSpells'!
0: 22 00 04 00 33 30 30 30 | "...3000
0: 22 00 04 00 33 30 30 30 | "...3000
0: 22 00 04 00 33 30 30 30 | "...3000
0: 0C 00 11 00 63 61 6E 74 - 20 63 61 73 74 20 61 6E | ....cant cast an
16: 79 6D 6F 72 65 | ymore
0: 0C 00 10 00 63 61 6E 74 - 20 74 61 6C 6B 20 65 69 | ....cant talk ei
16: 74 68 65 72 | ther
Possible deadlock attempt by 'SpellProcess::MActiveSpells'!
0: 0C 00 2F 00 77 65 6C 6C - 2E 20 49 20 64 69 64 20 | ../.well. I did
16: 61 20 2F 6C 65 76 65 6C - 20 38 30 2C 20 73 6F 20 | a /level 80, so
32: 69 20 77 61 73 20 6F 75 - 74 20 6F 66 20 68 65 61 | i was out of hea
48: 6C 74 68 | lth
0: 0C 00 03 00 6E 76 6D | ....nvm
0: 0C 00 06 00 6C 61 67 67 - 65 64 | ....lagged
0: 0C 00 05 00 61 68 68 21 - 21 | ....ahh!!
0: 0C 00 0C 00 74 68 61 74 - 20 77 61 73 20 69 74 21 | ....that was it!
0: 0C 00 13 00 67 72 61 62 - 62 69 6E 67 20 74 68 61 | ....grabbing tha
16: 74 2E 20 73 65 63 2E | t. sec.
0: 0C 00 03 00 3F 3F 3F | ....???
Possible deadlock attempt by 'SpellProcess::MActiveSpells'!
I was level 1, and did a /level 80 - and had barely a HP. So I used our CH script to give me all my health back. First time I did it, I wasn't targeted so I didn't think it worked. I pressed F1, cast the CH again but didn't see anything happen so I did it again thinking I mis-typed. The world reported a deadlock, the all the casts and chat came flying out.
I asked Scat to reproduce it, and he did. Cast the spell, couldn't type (echo), and finally you see the deadlock warning at the bottom.
In the TessDB, this is either spell ID 3 (Beta Heal) or 3000.