Server is really unstable

provocating · #1 06-07-2009, 12:30 AM

Okay I have only two players, me and my friend. I really have not had any problems and I do play from work on occasion, but nothing heavy duty because I play on a laptop.

I guess the server has been running about 3 months now with not much of a problem. I can seem to play all day long with no problems, but I do not do much for boss mobs. Now anytime my friend seems to be fighting some big, bad boss mob he has stability issues. Back when I was running a Windows server I could sometimes see his zone give a big error and go down, so I switched it to Linux last week hoping it would improve. It still was giving him issues so I purchased two copies of SoF thinking it could be his client, but the same thing. It always seems to do it when he is in some long ass battle though. I never hear him say it does it when he is just walking or something. Now the only real difference is that I am in my house and he is in another town, but we are on the same ISP.

As far as the server hardware it is all top notch, running in a VM and the VM's on this server never, ever give me problems so I know it is not that. Plus I can seem to play and leave my guy logged in with no issues.

I need ideas here though, he is getting really frustrated not being able to do any major raiding of fear of losing the battles.

provocating · #2 06-07-2009, 01:17 AM

I did happen to find this.

Code:

[Error] HandlePacket() Opcode error: Unexpected packet during CLIENT_CONNECTING: opcode: OP_BlockedBuffs (#420 eq=0x0000), size: 88
[Error] HandlePacket() Opcode error: Unexpected packet during CLIENT_CONNECTING: opcode: OP_BlockedBuffs (#420 eq=0x0000), size: 88
Unable to get raid id, char not found!
[Debug] [CLIENT__NET_ERR] Ellisar: Unhandled incoming opcode: [OpCode OP_WeaponEquip2 (0x5c2f) Size=8]
   0: DB 01 00 00 40 00 00 00                            | ....@...
[Debug] [CLIENT__NET_ERR] Ellisar: Unhandled incoming opcode: [OpCode OP_WeaponEquip2 (0x5c2f) Size=8]
   0: DB 01 00 00 80 00 00 00                            | ........
[Error] Consuming from empty slot 263
[Error] Consuming from empty slot 262
Client linkdead: Ellisar
Client disconnected (cs=d): Ellisar

provocating · #3 06-07-2009, 10:44 AM

Okay I have some more information. I can almost say what it is not.

I had him log in last night after it crashed. He stayed in PoK all night, when I got up at 7am his guy was still on. So I know it is not our connections. I also dropped the server to just 4 dynamic zones. I played for 2 hours this morning with no problems at all. I ask him to log in, he goes to Temple of Veeshan and fights his way to a bad guy, no problems whatsoever. The entire time I am doing a tail on zone-dynamic_02.log

I all of a sudden see VI give me a message that that file is now truncated...... Dumb me did not save it though. I get a text message from him saying he was killing Ikatair the Venom and he was at 6% and he froze up, the exact time the file was truncated. I watched the server stats at that time. The server was only using a few mb of memory, only using about 2-3 percent of the 4 cores, this server is a beast. This only happens on boss mobs, and this Ikatiar the Venom is a rogue, so no spells. He also said yesterday it happened with Lendiniara the Keeper three times. He has reported it on Sontalak, Trakanon, Itraeur Vius.....could this be Rampage ??

From seconds of him losing connection I got this.

Code:

2604 [06.07. - 09:07:23] Adding Ellisar to Rampage List in slot 0
2604 [06.07. - 09:07:26] Adding Daneal`s_pet000 to Rampage List in slot 1
2604 [06.07. - 09:07:26] Adding Daneal to Rampage List in slot 2
2604 [06.07. - 09:07:26] Adding Legbreaker to Rampage List in slot 3
2604 [06.07. - 09:07:26] Adding Synergy to Rampage List in slot 4
2604 [06.07. - 09:07:26] Adding Ranna`s_pet000 to Rampage List in slot 5
2604 [06.07. - 09:07:26] Adding Bookoo`s_pet000 to Rampage List in slot 6
2604 [06.07. - 09:07:26] Adding Bookoo to Rampage List in slot 7
2604 [06.07. - 09:07:26] Adding Ranna to Rampage List in slot 8
2604 [06.07. - 09:07:26] Adding Gretchen to Rampage List in slot 9
2604 [06.07. - 09:07:26] Adding Veruka to Rampage List in slot 10
2604 [06.07. - 09:07:26] Adding Nova to Rampage List in slot 11
2604 [06.07. - 09:07:26] Adding Strychnine to Rampage List in slot 12
2604 [06.07. - 09:07:26] Adding Shilah to Rampage List in slot 13
2604 [06.07. - 09:07:26] Adding Concussion to Rampage List in slot 14
2604 [06.07. - 09:07:26] Adding Alaya to Rampage List in slot 15
2604 [06.07. - 09:07:26] Adding Malador to Rampage List in slot 16
2604 [06.07. - 09:07:26] Adding Restless to Rampage List in slot 17
2604 [06.07. - 09:07:26] Adding Kinetic to Rampage List in slot 18
2604 [06.07. - 09:07:26] Adding Zorch to Rampage List in slot 19

provocating · #4 06-07-2009, 10:56 AM

We just did this again on Trakanon. The file got truncated in the big fight around a rampage time, could be coincidental that it was around a Rampage though. Here is the last of the zone file before the truncation and disconnect.

Code:

[Debug] Fading rune from slot 7
[Normal] Adding Ellisar to Rampage List in slot 2
[Normal] Adding Alaya to Rampage List in slot 3
[Normal] Adding Daneal`s_pet000 to Rampage List in slot 4
[Normal] Adding Painful`s_pet000 to Rampage List in slot 5
[Normal] Adding Celestia to Rampage List in slot 6
[Normal] Adding Meshka to Rampage List in slot 7
[Normal] Adding Nova to Rampage List in slot 8
[Normal] Adding Concussion to Rampage List in slot 9
[Normal] Adding Legbreaker to Rampage List in slot 10
[Normal] Adding Synergy to Rampage List in slot 11
[Normal] Adding Kinetic to Rampage List in slot 12
[Normal] Adding Restless`s_pet000 to Rampage List in slot 13
[Normal] Adding Zorch`s_pet000 to Rampage List in slot 14
[Normal] Adding Ranna`s_pet000 to Rampage List in slot 15
[Normal] Adding Strychnine`s_pet000 to Rampage List in slot 16
[Normal] Adding Meshka`s_Warder000 to Rampage List in slot 17
[Normal] Adding Bookoo`s_pet000 to Rampage List in slot 18
[Normal] Adding Veruka`s_pet000 to Rampage List in slot 19
[Debug] Fading rune from slot 14
[Debug] Fading rune from slot 6
[Debug] Concussion chance for a death save was 33 and the roll was 41
[Debug] Fading rune from slot 9
[Debug] Nova chance for a death save was 36 and the roll was 6
[Debug] Fading rune from slot 15
[Debug] Unknown slot being used by Ellisar, slot being used is: -1501
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 19, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 1e 01 00 00 be 30 00 00 - 53 74 72 79 63 68 6e 69  | .....0..Strychni
[Debug] [NET__STRUCT_HEX] 0016: 6e 65 00                -                          | ne.
[Debug] Fading rune from slot 2
[Debug] Fading rune from slot 5
[Debug] Fading rune from slot 9
[Debug] Fading rune from slot 15
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 13 01 00 00 be 30 00 00 - 52 65 73 74 6c 65 73 73  | .....0..Restless
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 19, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 23 01 00 00 be 30 00 00 - 53 68 61 73 74 72 69 6e  | #....0..Shastrin
[Debug] [NET__STRUCT_HEX] 0016: 73 61 00                -                          | sa.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 15, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 20 01 00 00 be 30 00 00 - 56 65 72 75 6b 61 00     |  ....0..Veruka.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 13 01 00 00 be 30 00 00 - 52 65 73 74 6c 65 73 73  | .....0..Restless
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] Fading rune from slot 16
[Debug] Fading spell rune from slot 5
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 25 01 00 00 be 30 00 00 - 43 65 6c 65 73 74 69 61  | %....0..Celestia
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Error] Consuming from empty slot 267
[Error] Consuming from empty slot 264
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 19, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 1e 01 00 00 be 30 00 00 - 53 74 72 79 63 68 6e 69  | .....0..Strychni
[Debug] [NET__STRUCT_HEX] 0016: 6e 65 00                -                          | ne.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 15, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 1d 01 00 00 be 30 00 00 - 53 68 69 6c 61 68 00     | .....0..Shilah.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 19, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 1e 01 00 00 be 30 00 00 - 53 74 72 79 63 68 6e 69  | .....0..Strychni
[Debug] [NET__STRUCT_HEX] 0016: 6e 65 00                -                          | ne.
[Debug] Fading spell rune from slot 6
[Debug] Fading spell rune from slot 8
[Debug] Fading spell rune from slot 9
[Debug] Kinetic chance for a death save was 35 and the roll was 69
[Debug] Fading rune from slot 11
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 22 01 00 00 be 30 00 00 - 56 61 6c 6b 79 72 69 65  | "....0..Valkyrie
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 16, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 21 01 00 00 be 30 00 00 - 50 61 69 6e 66 75 6c 00  | !....0..Painful.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 22 01 00 00 be 30 00 00 - 56 61 6c 6b 79 72 69 65  | "....0..Valkyrie
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 15, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 20 01 00 00 be 30 00 00 - 56 65 72 75 6b 61 00     |  ....0..Veruka.
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 13 01 00 00 be 30 00 00 - 52 65 73 74 6c 65 73 73  | .....0..Restless
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 15, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 20 01 00 00 be 30 00 00 - 56 65 72 75 6b 61 00     |  ....0..Veruka.
[Debug] Fading spell rune from slot 6
[Debug] Fading spell rune from slot 6
[Debug] Synergy chance for a death save was 35 and the roll was 69
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 17, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 17 01 00 00 be 30 00 00 - 47 72 65 74 63 68 65 6e  | .....0..Gretchen
[Debug] [NET__STRUCT_HEX] 0016: 00                      -                          | .
[Debug] Daneal`s pet chance for a death save was 34 and the roll was 83
[Debug] Veshila chance for a death save was 36 and the roll was 66
[Debug] [NET__STRUCTS] Wrong size on outbound OP_InterruptCast (InterruptCast_Struct): Got 15, expected 8
[Debug] [NET__STRUCT_HEX] 0000: 1a 01 00 00 be 30 00 00 - 42 6f 6f 6b 6f 6f 00     | .....0..Bookoo.
   0: 21 01 00 00 50 61 69 6E - 66 75 6C 00 00 00 00 00  | !...Painful.....
  16: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
  32: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
  48: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
  64: 00 00 00 00 06 00 00 00 - 01 02 00 00 02 00 00 00  | ................
  80: FF 00 00 00 FF FF FF FF - FF 00 00 00 FF 00 00 00  | ................
  96: FF 00 00 00 FF FF FF FF - FF FF 00 00 00 00 00 00  | ................
 112: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 128: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 144: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 160: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 176: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 192: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 208: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 224: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
 240: 00 00 00 00 00 00 00 00 - 00 00 00 00 00 00 00 00  | ................
[Debug] Bookoo`s pet chance for a death save was 38 and the roll was 98

**Derision** · #5 06-07-2009, 11:50 AM

As you are running Linux, you are well placed to try and track this down.

In a command prompt, before you run the script to start your zones, issue the command:

Code:

ulimit -c unlimited

to enable core dumps.

Run eqlaunch to start the zones, then when you get a crash, you will have a file called core or core.nnnnn (where nnnnn is a number) in the same directory as your zone executable.

Next fire up gdb in the same directory with the zone executable and the core dump

Code:

gdb ./zone <core dump file name>

At the (gdb) prompt, issue the command bt full. This will display a backtrace of the sequence of calls that lead up to the crash. You can copy and paste that here.

e.g.

Code:

Core was generated by `./zone dynamic_01 zones'.
Program terminated with signal 6, Aborted.
#0  0xb7f50410 in ?? ()
(gdb) bt full
#0  0xb7f50410 in ?? ()
No symbol table info available.
#1  0xbfb0ae3c in ?? ()
No symbol table info available.
#2  0x00000006 in ?? ()
No symbol table info available.
#3  0xb7b93c69 in abort () from /lib/libc.so.6
No symbol table info available.
#4  0x0818544d in command_optest (c=0x86bb8b8, sep=0xbfb0afcc) at command.cpp:850
No locals.
#5  0x081921ed in command_realdispatch (c=0x86bb8b8, message=0x86e720c "#optest") at command.cpp:657
        sep = {argnum = 0, arg = 0x86ddd30, argplus = 0x86ddca0, msg = 0x84064b8 "#optest", maxargnum = 10}
        cstr = {static npos = 4294967295,
  _M_dataplus = {<std::allocator<char>> = {<__gnu_cxx::new_allocator<char>> = {<No data fields>}, <No data fields>},
    _M_p = 0x86b164c "optest"}}
        cur = (._232 *) 0x83a4808
#6  0x080f04f7 in Client::ChannelMessageReceived (this=0x86bb8b8, chan_num=8 '\b', language=0 '\0', lang_skill=100 'd',
    message=0x86e720c "#optest", targetname=0x86e7178 "") at client.cpp:846
        sender = <value optimized out>
#7  0x081beae6 in Client::Handle_OP_ChannelMessage (this=0x3da0, app=0x86b15b0) at client_packet.cpp:2725
No locals.
#8  0x081cfe5d in Client::HandlePacket (this=0x86bb8b8, app=0x86b15b0) at client_packet.cpp:428
        opcode = <value optimized out>
#9  0x080fc1bf in Client::Process (this=0x86bb8b8) at client_process.cpp:616
        ranged = <value optimized out>
        may_use_attacks = false
        auto_attack_target = <value optimized out>
        ret = true
        app = (class EQApplicationPacket *) 0x0
#10 0x080df1c6 in EntityList::MobProcess (this=0x831de40) at entity.cpp:476
        iterator = {list = @0x831de78, current_element = 0x86b1688, dir = FORWARD}
#11 0x08107359 in main (argc=Cannot access memory at address 0x3da0
) at net.cpp:494
        error2 = 95 '_'
        dbaw = <value optimized out>
        zone_name = 0x82ae9ca "."
        Config = (const ZoneConfig *) 0x838b4c0
        retval = <value optimized out>
        InterserverTimer = {start_time = 20024, timer_time = 10000, enabled = true, set_at_trigger = 10000, pUseAcurateTiming = false}
        stream_identifier = {m_patches = {<std::_Vector_base<EQStreamIdentifier::Patch*,std::allocator<EQStreamIdentifier::Patch*> >> = {
      _M_impl = {<std::allocator<EQStreamIdentifier::Patch*>> = {<__gnu_cxx::new_allocator<EQStreamIdentifier::Patch*>> = {<No data fields>}, <N---Type <return> to continue, or q <return> to quit---
o data fields>}, _M_start = 0x8496e48, _M_finish = 0x8496e60, _M_end_of_storage = 0x8496e68}}, <No data fields>},
  m_streams = {<std::_Vector_base<EQStreamIdentifier::Record*,std::allocator<EQStreamIdentifier::Record*> >> = {
      _M_impl = {<std::allocator<EQStreamIdentifier::Record*>> = {<__gnu_cxx::new_allocator<EQStreamIdentifier::Record*>> = {<No data fields>}, <No data fields>}, _M_start = 0x86b9888, _M_finish = 0x86b9888, _M_end_of_storage = 0x86b988c}}, <No data fields>}, m_identified = {
    c = {<std::_Deque_base<EQStreamInterface*,std::allocator<EQStreamInterface*> >> = {
        _M_impl = {<std::allocator<EQStreamInterface*>> = {<__gnu_cxx::new_allocator<EQStreamInterface*>> = {<No data fields>}, <No data fields>}, _M_map = 0x8420190, _M_map_size = 8, _M_start = {_M_cur = 0x842035c, _M_first = 0x8420358, _M_last = 0x8420558, _M_node = 0x842019c},
          _M_finish = {_M_cur = 0x842035c, _M_first = 0x8420358, _M_last = 0x8420558, _M_node = 0x842019c}}}, <No data fields>}}}
        quest_timers = {start_time = 23144, timer_time = 1000, enabled = true, set_at_trigger = 1000, pUseAcurateTiming = false}
        worldwasconnected = true
        eqss = (class EQStream *) 0x0
        eqsi = (EQStreamInterface *) 0x0
        temp_timer = {start_time = 23224, timer_time = 10, enabled = true, set_at_trigger = 10, pUseAcurateTiming = false}
(gdb)

provocating · #6 06-07-2009, 12:45 PM

Ok, I am going to try this within the hour. And thanks for taking the time to message back.