SessionDisconnect's in 5.1.0.0

[Katana]

Since upgrading to 5.1.0.0 post DoD, I keep getting a problem randomly (but regularly) when I start ShowEQ, or when I zone. The application keeps running, but it loses all its data. No map (not even an outline) and no mobs or characters are listed. Its as though ShowEQ has lost contact with EQ itself. But having said that - whenever I zone after this has happened, I still see a MOTD: message in the output, and I still see when buffs wear off.

Im running ShowEQ 5.1.0.0 compiled from source on an FC-2 box.

Output from when ShowEQ starts, but contains no data, even after zoning a few times:

ShowEQ 5.1.0.0, released under the GPL.
SINS 0.5, released under the GPL.
All ShowEQ source code is Copyright (C) 2000-2005 by the respective ShowEQ Developers
ShowEQ comes with NO WARRANTY.

You may redistribute copies of ShowEQ under the terms of
The GNU General Public License.
See: http://www.gnu.org/copyleft/gpl.html for more details...

For updates and information, please visit http://seq.sourceforge.net/
ShowEQ 5.1.0.0, Built from 'main.cpp' on Sep 28 2005 at 20:08:43
CVS: @(#) $Id: main.cpp,v 1.34 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GCC version: 3.3.3
Using glibc version: 2.3
Using Qt version: 3.3.2
Using headers from linux version: 2.4.20
Using EQItemDB: @(#) $Id: itemdb.cpp,v 1.11 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GDBM: This is GDBM version 1.8.0, as of May 19, 1999.
Running on Linux release 2.6.5-1.358 for processor i686

Using config file '/root/.showeq/showeq.xml'
Loaded preferences file: /usr/local/share/showeq/seqdef.xml!
Loaded preferences file: /root/.showeq/showeq.xml!
Warning: Warning: Unknown payload typename 'utf8' for opcode '524e
Info: Listening for client: 192.168.0.1
Info: Initializing Packet Capture Thread:
Info: Filtering packets on device eth0, IP host 192.168.0.1
Info: Loaded 6827 spells from '/usr/local/share/showeq/spells_us.txt' maxSpell=0x1b76
Info: GuildMgr: Guildsfile loaded
Debug: ItemDB: Disabled
Info: Loading Filters from '/root'
Info: Loading Zone Filter File: /root
Info: Loading Zone Filter File: /root
Info: Categories Reloaded
Info: No Map found for zone 'unknown'!
Info: Checked for all variants of 'unknown.map', 'unknown.txt', and 'unknown_1.txt'
Info: in directories '/root/.showeq/maps' and '/usr/local/share/showeq/maps'!
Info: Loaded 12287 message strings from '/usr/local/share/showeq/eqstr_us.txt' maxFormat=46959
MOTD:
MOTD:
MOTD:
MOTD:

Output from when ShowEQ has been running happily, and then fails when zoning (and doesnt come back after a few more zone attempts):

Zone: ChangeCode: Client, Zone: draniksewersb
Warning: M Line 3352 in map '/usr/local/share/showeq/maps/draniksewersb.map' only had 1 points, not loading.
Info: Loaded map: '/usr/local/share/showeq/maps/draniksewersb.map'
Info: Saved spawn points: /root/.showeq/spawnpoints/dranik.sp
Warning: Can't find spawn point file /root/.showeq/spawnpoints/draniksewersb.sp
Info: Loading Zone Filter File: /root
Zone: Zoning, Please Wait... (Zone: 'draniksewersb')
Zone: ChangeCode: Server, Zone:draniksewersb
Zone: LogoutCode: Client logged out of server
Debug: PCAP Filter Set: udp[0:2] > 1024 and udp[2:2] > 1024 and ether proto 0x0800 and host 192.168.0.1
Info: EQPacket: SessionDisconnect detected, awaiting next zone session, pcap filter: EQ Client 192.168.0.1
MOTD:
MOTD:
MOTD:
Info: SpellItem 'Hastening of Salik' finished.
Info: SpellItem 'Cloud of Indifference' finished.
MOTD:

Has anybody seen this before? Does anybody have any clues on how to fix it? Im not sure what kind of info/logging would be helpful, so if you need any more data just let me know what and ill provide it.

Many thanks.

[purple]

What all do you have turned on in Interface->Terminal->MessageType Filter?

[Katana]

Absolutely everything is ticked.

[purple]

Do you have session tracking turned on?

[Katana]

Yes I do.

[purple]

What is your network layout? I assume 192.168.0.1 is your EQ client machine? Do you have multiple clients on the same machine? That seems like a weird IP for a client machine and more like the IP for a router, but IPs are just numbers I guess really.

When you only see MOTD, you're pretty much ignoring the zone server, which is what gives all the useful information. This is either because the packets from the zone server aren't being given to you because of your network layout, or because your pcap filter is stuck too tightly and so you miss the new SessionRequest (this would be a bug in seq).

[uRit1u2CBBA=]

Have you tried the kernel modifications to increase the size of the stored packets as explained here (http://www.showeq.net/forums/showthread.php?t=5333)?

[Katana]

Purple:

Yes - 192.168.0.1 is my EQ client. My EQ machine doesnt talk to the internet directly - its NATed behind an ADSL router. The router, the EQ Client, and the ShowEQ box are all connected on the LAN by a switch (im mirroring the client port onto the ShowEQ port in the switch IOS and its all been working successfully for me for 18 months now). Im 99.9% certain that the packets are making it to my ShowEQ box, because this setup has been working for me for so long pre-5.1.0.0. Plus, if you see my final paragraph below - it suggests that the packets are coming through ok.

uRit1u2CBBA=:

No - I havent seen that post before. My kernel still has the default settings so ill change them and recompile. Ill let you know how it goes.

Interesting development. If I turn OFF Session Tracking, my ShowEQ picks up every time I zone - without fail. However it then crashes out of the application altogether (this is why I turned Session Tracking on in the first place - ive never used it before 5.1.0.0 started crashing), so that doesnt really help. I get a glimpse of the skittles before everything goes back to a root prompt. If I turn on Session Tracking, the app stays up, but doesnt see any data. Im damned if I do - damned if I dont :)

Many thanks for the help and suggestions so far guys.

[Cryonic]

helps if you post the errors from the console when SEQ crashes as well as using gdb to perform a backtrace so the devs can see what SEQ was doing when it crashed.

[purple]

The only difference in 5.1 vs the 5.0.0.x is the some opcodes are wrong, but not that many. If turning session tracking off makes it keep the zones, it's definiately losing track of the zone server. If you only have one EQ client running that showeq sees, you might be able to tweak kernel params and turn off session tracking.

Otherwise, I don't know what to tell you. You might want to take a tcpdump and send it to me if you're comfortable doing that. To do that, tcpdump -i eth0 -s0 -w lookatmecrash.log 'udp && host 192.168.0.1' then gzip the dump and email it to [email protected]. Alternate, get on #showeq and /msg me a place to download it or some such. Only do this is you're comfortable with me knowing your char and guild and such, not that I'll do anything with it. Make sure you start the tcpdump after you login but that you zone once before seq breaks so I get the start of the stream cleanly. You can start it at char select if you want and that would be fine.

[Katana]

Thanks heaps for that Purple. I dont have any problems with you knowing my game details - thats a bit different from posting them publically :)

Ill try tweaking the kernel parameters first as suggested before by uRit1u2CBBA= to see if that lets me turn off Session Tracking and put everything back the way it was working before I upgraded. Its gonna take me a squillion hours to recompile a kernel tho :) Celeron 500 w/ 192 MB.

Or would you prefer I send you the tcpdump anyways to help determine if something is quirky in the code? Oh... I forgot to mention - im definitely only running a single session of EQ on the client.

Thanks again.

[purple]

Either way is fine with me. I'll just run the tcpdump through seq and if it borks for me, fix it. If it doesn't bork for me, I'll at least be able to watch the sessions move around and tell you if it is your network or not (I'm pretty sure it's not your network anyways).

[Katana]

Ok. Ive changed my kernel settings as suggested and unfortunately it hasnt really helped. With Session Tracking turned off, the app still crashes - although it does appear to stay up a little longer than before, and it seems to process some data before falling over. With Session Tracking turned on, its the same result - stable app but blank screens.

Ive emailed through two tcpdumps - one with session tracking on and one with it off. Umm... not that it matters to tcpdump what the application is doing. That was clever of me :o It makes more sense to do that with a gdb trace.

If you need me to provide a gdb dump, theres no problem - just let me know what you need.

Any other suggestions would be most welcome. Thanks so much for the help so far.

[purple]

Out of curiosity, what kernel parms did you change and what is the crash. I got the dump. I'll look over it when I have time.

[Katana]

Params are now set as:

[root@frodo root]# sysctl -a | grep net.core.rmem_default
net.core.rmem_default = 524288
[root@frodo root]# sysctl -a | grep net.core.rmem_max
net.core.rmem_max = 2097152
[root@frodo root]# sysctl -a | grep net.core.netdev_max_backlog
net.core.netdev_max_backlog = 3000

The crash seems to change slightly. Sometimes SEQ seems to die very quickly, and sometimes it seems to run a little longer. Following are two seperate console logs taken for two crashes. They were literally taken seconds apart, with no changes to the config made between them:

[root@frodo root]# showeq
ShowEQ 5.1.0.0, released under the GPL.
SINS 0.5, released under the GPL.
All ShowEQ source code is Copyright (C) 2000-2005 by the respective ShowEQ Developers
ShowEQ comes with NO WARRANTY.

You may redistribute copies of ShowEQ under the terms of
The GNU General Public License.
See: http://www.gnu.org/copyleft/gpl.html for more details...

For updates and information, please visit http://seq.sourceforge.net/
ShowEQ 5.1.0.0, Built from 'main.cpp' on Sep 28 2005 at 20:08:43
CVS: @(#) $Id: main.cpp,v 1.34 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GCC version: 3.3.3
Using glibc version: 2.3
Using Qt version: 3.3.2
Using headers from linux version: 2.4.20
Using EQItemDB: @(#) $Id: itemdb.cpp,v 1.11 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GDBM: This is GDBM version 1.8.0, as of May 19, 1999.
Running on Linux release 2.6.5-1.358 for processor i686

Using config file '/root/.showeq/showeq.xml'
Loaded preferences file: /usr/local/share/showeq/seqdef.xml!
Loaded preferences file: /root/.showeq/showeq.xml!
Warning: Warning: Unknown payload typename 'utf8' for opcode '524e
Info: Listening for client: 192.168.0.1
Info: Initializing Packet Capture Thread:
Info: Filtering packets on device eth0, IP host 192.168.0.1
Info: Loaded 6827 spells from '/usr/local/share/showeq/spells_us.txt' maxSpell=0x1b76
Info: GuildMgr: Guildsfile loaded
Debug: ItemDB: Disabled
Info: Loading Filters from '/root'
Info: Loading Zone Filter File: /root
Info: Loading Zone Filter File: /root
Info: Categories Reloaded
Info: No Map found for zone 'unknown'!
Info: Checked for all variants of 'unknown.map', 'unknown.txt', and 'unknown_1.txt'
Info: in directories '/root/.showeq/maps' and '/usr/local/share/showeq/maps'!
Info: Loaded 12287 message strings from '/usr/local/share/showeq/eqstr_us.txt' maxFormat=46959
MOTD: Greetings Norrathians! Share your Norrathian pride and honor your past, present, and future adventures by voting EverQuest to the "Walk of Game". Vote once a day through the end of the month at http://walkofgame.com/ and help make history!
Zone: EntryCode: Client
Aborted
[root@frodo root]#
[root@frodo root]# showeq
ShowEQ 5.1.0.0, released under the GPL.
SINS 0.5, released under the GPL.
All ShowEQ source code is Copyright (C) 2000-2005 by the respective ShowEQ Developers
ShowEQ comes with NO WARRANTY.

You may redistribute copies of ShowEQ under the terms of
The GNU General Public License.
See: http://www.gnu.org/copyleft/gpl.html for more details...

For updates and information, please visit http://seq.sourceforge.net/
ShowEQ 5.1.0.0, Built from 'main.cpp' on Sep 28 2005 at 20:08:43
CVS: @(#) $Id: main.cpp,v 1.34 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GCC version: 3.3.3
Using glibc version: 2.3
Using Qt version: 3.3.2
Using headers from linux version: 2.4.20
Using EQItemDB: @(#) $Id: itemdb.cpp,v 1.11 2005/09/13 15:23:11 cmmalone Exp $ $Name: $
Using GDBM: This is GDBM version 1.8.0, as of May 19, 1999.
Running on Linux release 2.6.5-1.358 for processor i686

Using config file '/root/.showeq/showeq.xml'
Loaded preferences file: /usr/local/share/showeq/seqdef.xml!
Loaded preferences file: /root/.showeq/showeq.xml!
Warning: Warning: Unknown payload typename 'utf8' for opcode '524e
Info: Listening for client: 192.168.0.1
Info: Initializing Packet Capture Thread:
Info: Filtering packets on device eth0, IP host 192.168.0.1
Info: Loaded 6827 spells from '/usr/local/share/showeq/spells_us.txt' maxSpell=0x1b76
Info: GuildMgr: Guildsfile loaded
Debug: ItemDB: Disabled
Info: Loading Filters from '/root'
Info: Loading Zone Filter File: /root
Info: Loading Zone Filter File: /root
Info: Categories Reloaded
Info: No Map found for zone 'unknown'!
Info: Checked for all variants of 'unknown.map', 'unknown.txt', and 'unknown_1.txt'
Info: in directories '/root/.showeq/maps' and '/usr/local/share/showeq/maps'!
Info: Loaded 12287 message strings from '/usr/local/share/showeq/eqstr_us.txt' maxFormat=46959
MOTD: Greetings Norrathians! Share your Norrathian pride and honor your past, present, and future adventures by voting EverQuest to the "Walk of Game". Vote once a day through the end of the month at http://walkofgame.com/ and help make history!
Zone: EntryCode: Client
Warning: M Line 338 in map '/usr/local/share/showeq/maps/guildhall.map' only had 1 points, not loading.
Info: Loaded map: '/usr/local/share/showeq/maps/guildhall.map'
Info: Loading Zone Filter File: /root
Zone: Zoning, Please Wait... (Zone: 'guildhall')
Player: Name: 'ABC123' Last: 'ILOVESHOWEQ'
Player: Level: 70
Player: PlayerMoney: P=248 G=0 S=0 C=0
Player: BankMoney: P=98211 G=8 S=0 C=7
Player: CursorMoney: P=0 G=0 S=0 C=0
Player: SharedMoney: P=8000
Player: DoN Crystals: Radiant=128 Ebon=0
Player: Exp: 2,783,357,989
Player: ExpAA: 4,224,420 (aa spent: 201, aa unspent: 1)
Player: Group:
Player: You have buff Howl of the Predator duration left is 703 in ticks.
Player: You have buff Blessing of Steeloak duration left is 731 in ticks.
Player: You have buff Talisman of the Tribunal duration left is 947 in ticks.
Player: You have buff Talisman of Sense duration left is 344 in ticks.
Player: You have buff Balikor's Mark duration left is 154 in ticks.
Player: You have buff Talisman of Might duration left is 307 in ticks.
Player: You have buff Talisman of Wunshi duration left is 556 in ticks.
Player: You have buff Brell's Brawny Bulwark duration left is 679 in ticks.
Player: You have buff Talisman of Fortitude duration left is 425 in ticks.
Player: You have buff Dead Men Floating duration left is 397 in ticks.
Player: You have buff Protection of Seasons duration left is 2228 in ticks.
Player: You have buff Spiritual Ascendance duration left is 280 in ticks.
Player: LDoN Earned Guk Points: 825
Player: LDoN Earned Mira Points: 235
Player: LDoN Earned MMC Points: 442
Player: LDoN Earned Ruj Points: 689
Player: LDoN Earned Tak Points: 528
Player: LDoN Unspent Points: 1,820
Debug: charProfile(-1.000000/-1.000000/-1.000000 - 0.000000)
Debug: Player::backfill(): Pos (-1.000000/-1.000000/-1.000000) Heading: 0.000000
Debug: Player::backfill(bind): Pos (412.196991/-295.464386/1.752001) Heading: 0.000000
Player: ExpAA: Set: 4,224,420 total, with 201 aapoints
Warning: M Line 338 in map '/usr/local/share/showeq/maps/guildhall.map' only had 1 points, not loading.
Info: Loaded map: '/usr/local/share/showeq/maps/guildhall.map'
Info: Loading Zone Filter File: /root
Zone: Zoning, Please Wait... (Zone: 'guildhall')
Debug: Player::zoneBegin(): Pos (-1.000000/-1.000000/-1.000000) Heading 0.000000
Zone: EntryCode: Server
Time: Sun Jan 11,3209 - 07:30 pm
Warning: INVALID PACKET: Bad CRC [192.168.0.1:1037 -> 224.0.0.252:3544] netOp 0060 seq 0000 len 40 crc (0001 != 1068)
Aborted
[root@frodo root]#
[root@frodo root]# date
Wed Oct 5 21:16:19 XXX 2005
[root@frodo root]#

As you can see... the first console log is a little different to the second - SEQ died almost immediately the first time, while the second time I had time to see skittles. Yet both were grabbed under pretty much identical circumstances. The only difference is that the first crashed while zoning from Guild Hall to Guild Lobby. The second crashed while zoning from Guild Lobby to Guild Hall.

Ive also done a backtrace using GDB. Output of the actual bt is:

Program received signal SIGABRT, Aborted.
[Switching to Thread -150121824 (LWP 15076)]
0x008f3402 in ?? ()
(gdb) bt
#0 0x008f3402 in ?? ()
#1 0x006e0e49 in raise () from /lib/tls/libc.so.6
#2 0x006e2872 in abort () from /lib/tls/libc.so.6
#3 0x001b6007 in __cxa_call_unexpected () from /usr/lib/libstdc++.so.5
#4 0x001b6044 in std::terminate () from /usr/lib/libstdc++.so.5
#5 0x001b61b6 in __cxa_throw () from /usr/lib/libstdc++.so.5
#6 0x001b640f in operator new () from /usr/lib/libstdc++.so.5
#7 0x001b64df in operator new[] () from /usr/lib/libstdc++.so.5
#8 0x08090a56 in EQProtocolPacket::decode (this=0xfee998b0, maxPayloadLength=1302462560) at packetformat.cpp:237
#9 0x08085baf in EQPacketStream::handlePacket (this=0x9e65a28, packet=@0xfee998b0) at packetstream.cpp:540
#10 0x0808d5c6 in EQPacket::dispatchPacket (this=0x9e79400, packet=@0xfee998b0) at packet.cpp:654
#11 0x0808d4d9 in EQPacket::dispatchPacket (this=0x9e79400, size=72, buffer=0xfee9992e "E") at packet.cpp:578
#12 0x0808f4be in EQPacket::qt_invoke (this=0x9e79400, _id=86, _o=0xfee9b9b0) at packet.cpp:398
#13 0x044f3a7c in QObject::activate_signal () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#14 0x044f38a4 in QObject::activate_signal () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#15 0x04831b8b in QTimer::timeout () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#16 0x04515182 in QTimer::event () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#17 0x044979ff in QApplication::internalNotify () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#18 0x04496ffe in QApplication::notify () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#19 0x04487355 in QEventLoop::activateTimers () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#20 0x044426db in QEventLoop::processEvents () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#21 0x044a9bf8 in QEventLoop::enterLoop () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#22 0x044a9aa8 in QEventLoop::exec () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#23 0x04497c51 in QApplication::exec () from /usr/lib/qt-3.3/lib/libqt-mt.so.3
#24 0x08067cc5 in main (argc=1, argv=0x9f94dd0) at main.cpp:702
(gdb) quit

BTW... this thread http://www.showeq.net/forums/showthread.php?t=5408 appears to be describing exactly the same scenario that im seeing. Unfortunately the discussion just kinda dies out with no resolution :( But at least it seems as though its not just me.

Sorry... thats a heap of information for a single post. I dont mean to spam the thread, im just trying to give you as much debug as I can.

Thanks again guys.

[purple]

More information is infinitely better than too little information. I'll look into things when I can. Thanks for the details.

[purple]

This looks like it's totally showeq's fault. I'll try to get a new release tomorrow evening once I fix it. Or maybe tonight if I can squeeze some extra time somewhere. There's some Microsoft IPv6<->IPv4 gateway traffic that is interacting poorly with showeq.

Sorry about the trouble and thanks for the tcpdumps. Never would have gotten anywhere fixing this without them.

[Katana]

Thats magic Purple. Im only glad that I could help. Thanks so much for looking at the problem and taking your own time to help.

In fact, id like to extend my appreciation to the people who wrote and also continue to maintain ShowEQ. Its a great tool and the generous time which goes into keeping it working after every patch deserves some gratitude.

You have my sincerest thanks guys :)

[uRit1u2CBBA=]

5.2 was just released - see if using that fixed your problem, of if it still exists.

[Katana]

Yep, 5.2 fixes it :)