Critical: World slowness, zone & client issues, blah.

Post by **xinux** » Thu Sep 08, 2011 4:59 pm

Ok take this post with a grain of salt mostly just me talking my self through this.

** it's readable if you select all and past into notepad **

Going through the log's here are the parts that looked odd to me.

Trying to log slasher back after client/world stopped responding.

What it normally repsond's with

Code: Select all

21:51:05 D Player: Loading character_details for 'Tttt' (char_id: 30)
21:51:05 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_LoginByNumRequestMsg'
21:51:05 D Client: SendLoginInfo to new client...
21:51:05 D World: Increment Server_Accepted_Connection + 1

what i see is this then nothing

Code: Select all

22:21:39 D Player: Loading character_details for 'Slasher' (char_id: 17)

Trying to /zone after world lock with character ingame and repsonding normal commands.

What it normally repsond's with

Code: Select all

22:01:32 D Spells: Saving Spell(s) for Player: 'Vvvv'
22:01:32 D Items: Save Items for Player 29
22:01:32 D Merchant: Saving Buybacks - Player: 29
22:01:33 D Net: New client from ip: 192.168.1.100 port: 52056
22:01:33 D Net: Adding new client...
22:01:33 D Client: Client::Process, ProcessQuestUpdates
22:01:33 D Opcode: Opcode 0002 (2): OP_LoginByNumRequestMsg

what i got was the following and at 22:42:22 is when i forced closed the client

Code: Select all

22:37:21 D Spells: Saving Spell(s) for Player: 'Hhhh'
22:37:21 D Items: Save Items for Player 31
22:37:21 D Merchant: Saving Buybacks - Player: 31
22:42:21 I Zone: Initiating zone shutdown of 'TimorousDeep'
22:42:22 I Zone: Completed zone shutdown of 'TimorousDeep'
22:42:22 I Zone: Initiating zone shutdown of 'Darklight'
22:42:23 I Zone: Completed zone shutdown of 'Darklight'

Did a camp command with Tttt at 22:09:58 why is there 2 saves at the same time?

Code: Select all

22:09:58 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_RequestCampMsg'
22:09:58 T Opcode: Opcode 01AD (429): OP_UpdatePositionMsg
22:09:58 D Player: Tttt left grid 4294967295 and entered grid 1701767597
22:09:58 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdatePositionMsg'
22:10:06 Q DBCore: replace into variables (variable_name, variable_value) values('gametime', '0/22/3800 11:41')
22:10:06 D DBCore: Query returned no results in DBcore::RunQuery!replace into variables (variable_name, variable_value) values('gametime', '0/22/3800 11:41')
22:10:08 T Opcode: Opcode 01AD (429): OP_UpdatePositionMsg
22:10:08 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdatePositionMsg'
22:10:18 T Opcode: Opcode 01AD (429): OP_UpdatePositionMsg
22:10:18 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdatePositionMsg'
22:10:20 Q DBCore: update characters set unix_timestamp=1315372220 where id=30 and account_id=5636
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update characters set unix_timestamp=1315372220 where id=30 and account_id=5636
22:10:20 Q DBCore: update characters set current_zone_id=263, x=-261.229004, y=2.443580, z=183.220001, heading=322.375000, level=1,instance_id=0,last_saved=1315372220, `class`=4 where id = 30
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update characters set current_zone_id=263, x=-261.229004, y=2.443580, z=183.220001, heading=322.375000, level=1,instance_id=0,last_saved=1315372220, `class`=4 where id = 30
22:10:20 Q DBCore: update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 1.000000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 30
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 1.000000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 30
22:10:20 D Player: Saving Player Factions...
22:10:20 D Spells: Saving Spell(s) for Player: 'Tttt'
22:10:20 D Items: Save Items for Player 30
22:10:20 D Merchant: Saving Buybacks - Player: 30
22:10:20 I Zone: Scheduling client 'Tttt' for removal.
22:10:20 D Player: Toggling Character OFFLINE!
22:10:20 Q DBCore: UPDATE characters SET is_online=0 WHERE id = 30;
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE characters SET is_online=0 WHERE id = 30;
22:10:20 Q DBCore: update characters set unix_timestamp=1315372220 where id=30 and account_id=5636
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update characters set unix_timestamp=1315372220 where id=30 and account_id=5636
22:10:20 Q DBCore: update characters set current_zone_id=263, x=-261.229004, y=2.443580, z=183.220001, heading=322.375000, level=1,instance_id=0,last_saved=1315372220, `class`=4 where id = 30
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update characters set current_zone_id=263, x=-261.229004, y=2.443580, z=183.220001, heading=322.375000, level=1,instance_id=0,last_saved=1315372220, `class`=4 where id = 30
22:10:20 Q DBCore: update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 1.000000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 30
22:10:20 D DBCore: Query returned no results in DBcore::RunQuery!update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 1.000000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 30
22:10:20 D Player: Saving Player Factions...
22:10:20 D Spells: Saving Spell(s) for Player: 'Tttt'
22:10:20 D Items: Save Items for Player 30
22:10:20 D Merchant: Saving Buybacks - Player: 30
22:10:22 Q DBCore: update characters set unix_timestamp=1315372222 where id=17 and account_id=5635
22:10:22 D DBCore: Query returned no results in DBcore::RunQuery!update characters set unix_timestamp=1315372222 where id=17 and account_id=5635
22:10:22 Q DBCore: update characters set current_zone_id=253, x=6.328205, y=-6.375487, z=209.886322, heading=84.093750, level=1,instance_id=0,last_saved=1315372222, `class`=9 where id = 17
22:10:22 D DBCore: Query returned no results in DBcore::RunQuery!update characters set current_zone_id=253, x=6.328205, y=-6.375487, z=209.886322, heading=84.093750, level=1,instance_id=0,last_saved=1315372222, `class`=9 where id = 17
22:10:22 Q DBCore: update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 12.500000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 17
22:10:22 D DBCore: Query returned no results in DBcore::RunQuery!update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 12.500000,bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 17
22:10:22 D Player: Saving Player Factions...
22:10:22 Q DBCore: insert into character_factions (char_id, faction_id, faction_level) values(17, 21, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:10:22 R DBCore: No Result.
22:10:22 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_factions (char_id, faction_id, faction_level) values(17, 21, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:10:22 Q DBCore: insert into character_factions (char_id, faction_id, faction_level) values(17, 22, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:10:22 R DBCore: No Result.
22:10:22 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_factions (char_id, faction_id, faction_level) values(17, 22, 0) ON DUPLICATE KEY UPDATE faction_level=0

The last activity i see from Slasher 22:10:22

Code: Select all

22:10:22 D Spells: Saving Spell(s) for Player: 'Slasher'
22:10:22 D Items: Save Items for Player 17
22:10:22 D Merchant: Saving Buybacks - Player: 17
22:10:22 D Opcode: Opcode 201D (8221): ServerOP_LoginEquipment
22:10:22 D Login: Looking for Login Appearance Updates...
22:10:22 Q DBCore: SELECT ci.id, ci.char_id, equip_type, red, green, blue, highlight_red, highlight_green, highlight_blue, ci.slot FROM characters c JOIN character_items ci ON c.id = ci.char_id JOIN item_appearances ia ON ci.item_id = ia.item_id WHERE c.deleted = 0 AND ci.type = 'EQUIPPED' AND ( ci.slot <= 8 OR ci.slot = 19 ) AND ci.login_checksum <> CRC32(CRC32(`ci`.`type`) + CRC32(ci.slot) + CRC32(ci.item_id))
22:10:22 D DBCore: Query Successful, 0 rows returned
22:10:30 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:10:30 D DBCore: Query Successful, 1 rows returned
22:10:30 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372230;
22:10:30 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372230;
22:10:30 Q DBCore: SELECT COUNT(id) FROM characters
22:10:30 D DBCore: Query Successful, 1 rows returned
22:10:30 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372230;
22:10:30 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372230;
22:10:30 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:10:30 D DBCore: Query Successful, 1 rows returned
22:10:30 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372230;
22:10:30 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372230) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372230;
22:10:32 D World: Removing connection...
22:11:22 Q DBCore: update characters set unix_timestamp=1315372282 where id=17 and account_id=5635
22:11:22 D DBCore: Query returned no results in DBcore::RunQuery!update characters set unix_timestamp=1315372282 where id=17 and account_id=5635
22:11:22 Q DBCore: update characters set current_zone_id=253, x=6.328205, y=-6.375487, z=209.886322, heading=84.093750, level=1,instance_id=0,last_saved=1315372282, `class`=9 where id = 17
22:11:22 D DBCore: Query returned no results in DBcore::RunQuery!update characters set current_zone_id=253, x=6.328205, y=-6.375487, z=209.886322, heading=84.093750, level=1,instance_id=0,last_saved=1315372282, `class`=9 where id = 17
22:11:22 Q DBCore: update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 12.500000, bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 17
22:11:22 D DBCore: Query returned no results in DBcore::RunQuery!update character_details set hp=40, power=45, str=20, sta=20, agi=20, wis=20, intel=20, heat=0, cold=0, magic=0, mental=0, divine=0, disease=0, poison=0, coin_copper=0, coin_silver=0, coin_gold=0, coin_plat=0, max_hp = 40, max_power=45, xp = 0, xp_needed = 100, xp_debt = 0, xp_vitality = 12.500000,bank_copper = 0, bank_silver = 0, bank_gold = 0, bank_plat = 0, bind_zone_id=0, bind_x = 0.000000, bind_y = 0.000000, bind_z = 0.000000, bind_heading = 0.000000, house_zone_id=0, combat_voice = 52, emote_voice = 1060, biography='' where char_id = 17
22:11:22 D Player: Saving Player Factions...
22:11:22 Q DBCore: insert into character_factions (char_id, faction_id, faction_level) values(17, 21, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:11:22 R DBCore: No Result.
22:11:22 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_factions (char_id, faction_id, faction_level) values(17, 21, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:11:22 Q DBCore: insert into character_factions (char_id, faction_id, faction_level) values(17, 22, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:11:22 R DBCore: No Result.
22:11:22 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_factions (char_id, faction_id, faction_level) values(17, 22, 0) ON DUPLICATE KEY UPDATE faction_level=0
22:11:22 D Spells: Saving Spell(s) for Player: 'Slasher'
22:11:22 D Items: Save Items for Player 17
22:11:22 D Merchant: Saving Buybacks - Player: 17

Post by **xinux** » Thu Sep 08, 2011 5:01 pm

At this point is when i created another character and logged in and was fine till i /zone but slasher never could log back in after locking.

Code: Select all

22:11:31 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:11:31 D DBCore: Query Successful, 1 rows returned
22:11:31 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372291;
22:11:31 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372291;
22:11:31 Q DBCore: SELECT COUNT(id) FROM characters
22:11:31 D DBCore: Query Successful, 1 rows returned
22:11:31 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372291;
22:11:31 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372291;
22:11:31 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:11:31 D DBCore: Query Successful, 1 rows returned
22:11:31 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372291;
22:11:31 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372291) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372291;
22:12:32 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:12:49 D DBCore: Query Successful, 1 rows returned
22:12:49 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372369;
22:12:49 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372369;
22:12:49 Q DBCore: SELECT COUNT(id) FROM characters
22:12:49 D DBCore: Query Successful, 1 rows returned
22:12:49 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372369;
22:12:49 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372369;
22:12:49 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:12:49 D DBCore: Query Successful, 1 rows returned
22:12:49 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372369;
22:12:49 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372369) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372369;
22:13:33 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:13:33 D DBCore: Query Successful, 1 rows returned
22:13:33 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372413;
22:13:33 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372413;
22:13:33 Q DBCore: SELECT COUNT(id) FROM characters
22:13:33 D DBCore: Query Successful, 1 rows returned
22:13:33 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372413;
22:13:33 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372413;
22:13:33 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:13:33 D DBCore: Query Successful, 1 rows returned
22:13:33 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372413;
22:13:33 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372413) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372413;
22:14:34 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:14:34 D DBCore: Query Successful, 1 rows returned
22:14:34 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372474;
22:14:34 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372474;
22:14:34 Q DBCore: SELECT COUNT(id) FROM characters
22:14:34 D DBCore: Query Successful, 1 rows returned
22:14:34 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372474;
22:14:34 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 6, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 6, stat_date = 1315372474;
22:14:34 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:14:34 D DBCore: Query Successful, 1 rows returned
22:14:34 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372474;
22:14:34 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372474) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372474;
22:14:57 D Opcode: Opcode 2013 (8211): ServerOP_CharacterCreate
22:14:57 D World: Name check on: Hhhh
22:14:57 Q DBCore: SELECT count(*) FROM characters WHERE name='Hhhh'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT count(*) FROM name_filter WHERE 'Hhhh' like name
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 D World: Response: 1
22:14:57 Q DBCore: SELECT min(admin_status) FROM characters where account_id=5636
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name=''
22:14:57 D DBCore: Query Successful, 0 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name=''
22:14:57 D DBCore: Query Successful, 0 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='ec/pc/iksar/iksar_male'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/hair/hair002'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name=''
22:14:57 D DBCore: Query Successful, 0 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/wearable_items/starter_clothes/iksar_male/chest'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/wearable_items/starter_clothes/iksar_male/legs'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='ec/pc/iksar/iksar_male'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/hair/hair014'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/wearable_items/starter_clothes/iksar_male/legs'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name='accessories/wearable_items/starter_clothes/iksar_male/chest'
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 Q DBCore: SELECT appearance_id FROM appearances where name=''
22:14:57 D DBCore: Query Successful, 0 rows returned
22:14:57 Q DBCore: Insert into characters (account_id, server_id, name, race, class, gender, deity,body_size, body_age, soga_wing_type, soga_chest_type, soga_legs_type, soga_hair_type, soga_model_type, legs_type, chest_type, wing_type, hair_type, model_type, facial_hair_type, soga_facial_hair_type, created_date, last_saved) values(5636, 2080, 'Hhhh', 10, 9, 1, 0, 0.210000, 0.000000, 0, 5541, 5542, 1129, 103, 5542, 5541, 0, 1136, 103, 0, 0, now(), unix_timestamp())
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!Insert into characters (account_id, server_id, name, race, class, gender, deity, body_size, body_age, soga_wing_type, soga_chest_type, soga_legs_type, soga_hair_type, soga_model_type, legs_type, chest_type, wing_type, hair_type, model_type, facial_hair_type, soga_facial_hair_type, created_date, last_saved) values(5636, 2080, 'Hhhh', 10, 9, 1, 0, 0.210000, 0.000000, 0, 5541, 5542, 1129, 103, 5542,5541, 0, 1136, 103, 0, 0, now(), unix_timestamp())
22:14:57 Q DBCore: insert into character_factions (char_id, faction_id, faction_level) select 31, faction_id, value FROM starting_factions where starting_city=8
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_factions (char_id, faction_id, faction_level) select 31, faction_id, value FROM starting_factions where starting_city=8
22:14:57 D Player: Adding default zone for race: 10, class: 9 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:57 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:57 Q DBCore: SELECT `name` FROM starting_zones sz, zones z WHERE sz.zone_id = z.id AND class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D DBCore: Query Successful, 0 rows returned
22:14:57 Q DBCore: UPDATE characters c, zones z SET c.current_zone_id = z.id, c.x = z.safe_x, c.y =z.safe_y, c.z = z.safe_z, c.starting_city = 8 WHERE z.start_zone = 8 and c.id = 31
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE characters c, zones z SET c.current_zone_id = z.id, c.x = z.safe_x, c.y = z.safe_y, c.z = z.safe_z, c.starting_city = 8 WHERE z.start_zone = 8 and c.id = 31
22:14:57 Q DBCore: SELECT name FROM zones where start_zone = 8
22:14:57 D DBCore: Query Successful, 1 rows returned
22:14:57 D Player: Setting New Character Starting Zone to 'Darklight' FROM player choice.
22:14:57 D Player: Adding default items for race: 10, class: 9 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:57 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:57 Q DBCore: SELECT `type`, item_id, creator, condition_, attuned, count FROM starting_items WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255) ORDER BY id
22:14:57 D DBCore: Query Successful, 5 rows returned
22:14:57 Q DBCore: insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'NOT-EQUIPPED', 0, 1, '', 100, 0, 0, 1)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'NOT-EQUIPPED', 0, 1, '', 100, 0, 0, 1)
22:14:57 Q DBCore: insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'NOT-EQUIPPED', 1, 220291, '', 100, 0, 0, 1)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'NOT-EQUIPPED', 1, 220291, '', 100, 0, 0, 1)
22:14:57 Q DBCore: insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 22, 161463, '', 100, 0, 0, 20)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 22, 161463, '', 100, 0, 0, 20)
22:14:57 Q DBCore: insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 23, 161113, '', 100, 0, 0, 20)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 23, 161113, '', 100, 0, 0, 20)
22:14:57 Q DBCore: insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 16, 172229, '', 100, 0, 0, 1)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!insert into character_items (char_id, type, slot, item_id, creator, condition_, attuned, bag_id, count) values(31, 'EQUIPPED', 16, 172229, '', 100, 0, 0, 1)
22:14:57 D Player: Adding default skills for race: 10, class: 9 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:57 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:57 Q DBCore: INSERT IGNORE INTO character_skills (char_id, skill_id, current_val, max_val) SELECT 31, skill_id, current_val, max_val FROM starting_skills WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!INSERT IGNORE INTO character_skills (char_id, skill_id, current_val, max_val) SELECT 31, skill_id, current_val, max_val FROM starting_skills WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D Player: Adding default spells for race: 10, class: 9 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:57 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:57 Q DBCore: INSERT IGNORE INTO character_spells (char_id, spell_id, knowledge_slot) SELECT 31, spell_id, knowledge_slot FROM starting_spells WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!INSERT IGNORE INTO character_spells (char_id, spell_id, knowledge_slot) SELECT 31, spell_id, knowledge_slot FROM starting_spells WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D Player: Adding default skillbar for race: 10, class: 9 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:57 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:57 Q DBCore: INSERT IGNORE INTO character_skillbar (char_id, type, hotbar, spell_id, slot, text_val) SELECT 31, type, hotbar, spell_id, slot, text_val FROM starting_skillbar WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D DBCore: Query returned no results in DBcore::RunQuery!INSERT IGNORE INTO character_skillbar (char_id, type, hotbar, spell_id, slot, text_val) SELECT 31, type, hotbar, spell_id, slot, text_val FROM starting_skillbar WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255)
22:14:57 D Player: Adding default titles for race: 10, class: 9, gender: 1 for char_id: 31
22:14:57 D World: Classes::GetBaseClass returning base class ID: 1
22:14:58 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:14:58 Q DBCore: INSERT IGNORE INTO character_titles (char_id, title_id) SELECT 31, title_id FROM starting_titles WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255) and gender_id IN (1, 255)
22:14:58 R DBCore: No Result.
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!INSERT IGNORE INTO character_titles (char_id, title_id) SELECT 31, title_id FROM  starting_titles WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255) and gender_id IN (1, 255)
22:14:58 Q DBCore: INSERT INTO `character_details` (`char_id`) VALUES (31)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO `character_details` (`char_id`) VALUES (31)
22:14:58 Q DBCore: UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 10 AND class_id = 9 AND char_id = 31
22:14:58 R DBCore: No Result.
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 10 AND class_id= 9 AND char_id = 31
22:14:58 Q DBCore: UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 255 AND class_id = 9 AND char_id = 31
22:14:58 R DBCore: No Result.
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 255 AND class_id = 9 AND char_id = 31
22:14:58 Q DBCore: UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 10 AND class_id = 255 AND char_id = 31
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE character_details c, starting_details s SET c.max_hp = s.max_hp, c.max_power = s.max_power, c.str = s.str, c.sta = s.sta, c.agi = s.agi, c.wis = s.wis, c.intel = s.intel,c.heat = s.heat, c.cold = s.cold, c.magic = s.magic, c.mental = s.mental, c.divine = s.divine, c.disease = s.disease, c.poison = s.poison, c.coin_copper = s.coin_copper, c.coin_silver = s.coin_silver, c.coin_gold = s.coin_gold, c.coin_plat = s.coin_plat, c.status_points = s.status_points WHERE s.race_id = 10 AND class_id= 255 AND char_id = 31
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'skin_color',12,38,42)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'skin_color',12,38,42)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'eye_color',204,204,204)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'eye_color',204,204,204)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_color1',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_color1',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_color2',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_color2',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_highlight',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_highlight',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_type_color',12,38,42)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_type_color',12,38,42)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_type_highlight_color',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_type_highlight_color',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_face_color',12,38,42)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_face_color',12,38,42)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'hair_face_highlight_color',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'hair_face_highlight_color',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'wing_color1',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'wing_color1',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'wing_color2',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'wing_color2',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'shirt_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'shirt_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'unknown_chest_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'unknown_chest_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'pants_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'pants_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'unknown_legs_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'unknown_legs_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'unknown9',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'unknown9',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'eye_type',-97,0,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'eye_type',-97,0,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'ear_type',0,0,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'ear_type',0,0,0,1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'eye_brow_type',94,-53,-41, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'eye_brow_type',94,-53,-41, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'cheek_type',34,-3,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'cheek_type',34,-3,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'lip_type',81,-81,88, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'lip_type',81,-81,88, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'chin_type',8,7,-26, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'chin_type',8,7,-26, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'nose_type',-26,-88,41, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'nose_type',-26,-88,41, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'body_size',20,0,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'body_size',20,0,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_skin_color',95,173,109)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_skin_color',95,173,109)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_eye_color',39,76,55)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_eye_color',39,76,55)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_color1',204,204,204)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_color1',204,204,204)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_color2',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_color2',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_highlight',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_highlight',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_type_color',95,173,109)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_type_color',95,173,109)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_type_highlight_color',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_type_highlight_color',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_face_color',95,173,109)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_face_color',95,173,109)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_face_highlight_color',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_hair_face_highlight_color',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_wing_color1',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_wing_color1',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_wing_color2',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_wing_color2',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_shirt_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_shirt_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown_chest_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown_chest_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_pants_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_pants_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown_legs_color',255,255,255)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown_legs_color',255,255,255)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown13',0,0,0)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue) values(31,'soga_unknown13',0,0,0)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_eye_type',0,0,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_eye_type',0,0,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_ear_type',0,0,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_ear_type',0,0,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_eye_brow_type',3,-65,-31, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_eye_brow_type',3,-65,-31, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_cheek_type',62,72,0, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_cheek_type',62,72,0, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_lip_type',-17,-76,78, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_lip_type',-17,-76,78, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_chin_type',-62,-20,32, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_chin_type',-62,-20,32, 1)
22:14:58 Q DBCore: insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_nose_type',52,-28,14, 1)
22:14:58 D DBCore: Query returned no results in DBcore::RunQuery!insert into char_colors (char_id, type, red, green, blue, signed_value) values(31,'soga_nose_type',52,-28,14, 1)
22:15:05 D Opcode: Opcode AB00 (43776): ServerOP_UsertoWorldReq
22:15:05 Q DBCore: SELECT min(admin_status) FROM characters where account_id=5636
22:15:05 D DBCore: Query Successful, 1 rows returned
22:15:05 Q DBCore: SELECT admin_status FROM characters where account_id=5636 and id=31
22:15:05 D DBCore: Query Successful, 1 rows returned
22:15:05 Q DBCore: SELECT name FROM characters where id=31
22:15:05 D DBCore: Query Successful, 1 rows returned
22:15:05 D Net: AddAuth: 5636 Key: 1315372505
22:15:06 D Net: New client from ip: 192.168.1.100 port: 52059
22:15:06 D Net: Adding new client...
22:15:06 D Opcode: Opcode 0002 (2): OP_LoginByNumRequestMsg
22:15:06 I ZoneAuth: Access Key: 1315372505, Character Name: Hhhh, Account ID: 5636
22:15:06 Q DBCore: SELECT id, current_zone_id, x, y, z, heading, admin_status, race, model_type, class, deity, level, gender, tradeskill_level, wing_type, hair_type, chest_type, legs_type, soga_wing_type, soga_hair_type, soga_chest_type, soga_legs_type, 0xFFFFFFFF - crc32(name), facial_hair_type, soga_facial_hair_type,instance_id,last_saved, DATEDIFF(curdate(), created_date) as accage FROM characters where name='Hhhh' and account_id=5636
22:15:06 D DBCore: Query Successful, 1 rows returned
22:15:06 D Player: Loading character for 'Hhhh' (char_id: 31)
22:15:06 Q DBCore: SELECT ci.id,ci.instance_id,ci.grant_reenter_time_left,ci.grant_reset_time_left,ci.lockout_time,inst.zone_id FROM character_instances as ci,instances as inst where ci.char_id=31 and inst.id=ci.instance_id
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT name FROM zones where id = 34
22:15:06 D DBCore: Query Successful, 1 rows returned
22:15:06 I Zone: Loading new Zone 'Darklight'
22:15:06 Q DBCore: SELECT id, file, description, underworld, safe_x, safe_y, safe_z, min_status, min_level, max_level, instance_type, shutdown_timer, zone_motd, default_reenter_time, default_reset_time, default_lockout_time, force_group_to_zone, safe_heading, xp_modifier, ruleset_id FROM zones where name='Darklight'
22:15:06 D DBCore: Query Successful, 1 rows returned
22:15:06 D World: Classes::GetBaseClass returning base class ID: 1
22:15:06 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:15:06 Q DBCore: SELECT `name`, `type` FROM `character_social` WHERE `char_id`=31
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT `guild_id` FROM `guild_members` WHERE `char_id`=31
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT stat_id, stat_value, stat_date FROM statistics WHERE char_id=31
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT sln.id, sle.id, slp.x, slp.y, slp.z, slp.x_offset, slp.y_offset, slp.z_offset, slp.heading, sle.spawn_id, sle.spawnpercentage, slp.respawn, slp.grid_id, slp.id, slp.expire_timer, slp.expire_offset FROM spawn_location_placement slp, spawn_location_name sln, spawn_location_entry sle, spawn_npcs sn where sn.spawn_id = sle.spawn_id and sln.id = sle.spawn_location_id and sln.id = slp.spawn_location_id and slp.zone_id=34 ORDER BY sln.id, sle.id
22:15:06 D DBCore: Query Successful, 1361 rows returned
22:15:06 Q DBCore: SELECT `collection_id`,`completed` FROM `character_collections` WHERE `char_id`=31
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT recipe_id FROM character_recipes WHERE char_id = 31
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 D Recipes: Loaded 0 recipes for player: Hhhh (31)
22:15:06 Q DBCore: SELECT distinct `type` FROM char_colors where length(type) > 0 and char_id=31
22:15:06 D DBCore: Query Successful, 47 rows returned
22:15:06 Q DBCore: SELECT `type`, char_id, signed_value, red, green, blue FROM char_colors where length(type) > 0 and char_id=31
22:15:06 D DBCore: Query Successful, 47 rows returned
22:15:06 Q DBCore: SELECT sln.id, sle.id, slp.x, slp.y, slp.z, slp.x_offset, slp.y_offset, slp.z_offset, slp.heading, sle.spawn_id, sle.spawnpercentage, slp.respawn, slp.grid_id, slp.id, slp.expire_timer, slp.expire_offset FROM spawn_location_placement slp, spawn_location_name sln, spawn_location_entry sle, spawn_objects so where so.spawn_id = sle.spawn_id and sln.id = sle.spawn_location_id and sln.id = slp.spawn_location_id and slp.zone_id=34 ORDER BY sln.id, sle.id
22:15:06 D DBCore: Query Successful, 37 rows returned
22:15:06 Q DBCore: SELECT hp, power, max_concentration, attack, mitigation, avoidance, parry, deflection, block, str, sta, agi, wis, intel, heat, cold, magic, mental, divine, disease, poison, coin_copper, coin_silver, coin_gold, coin_plat, pet_name, status_points, bind_zone_id, bind_x, bind_y, bind_z, bind_heading, house_zone_id, max_hp, max_power, xp, xp_needed, xp_debt, xp_vitality, bank_copper, bank_silver, bank_gold, bank_plat, combat_voice, emote_voice, biography FROM character_details WHERE char_id=31
22:15:06 D DBCore: Query Successful, 1 rows returned
22:15:06 22:15:06 D Q Player: DBCore: Loading character_details for 'Hhhh' (char_id: 31)SELECT sln.id, sle.id, slp.x, slp.y, slp.z, slp.x_offset, slp.y_offset, slp.z_offset, slp.heading, sle.spawn_id, sle.spawnpercentage, slp.respawn, slp.grid_id, slp.id, slp.expire_timer, slp.expire_offset FROM spawn_location_placement slp, spawn_location_name sln, spawn_location_entry sle, spawn_widgets sw where sw.spawn_id = sle.spawn_id and sln.id = sle.spawn_location_id and sln.id = slp.spawn_location_id and slp.zone_id=34 ORDER BY sln.id, sle.id
22:15:06 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_LoginByNumRequestMsg'
22:15:06 D DBCore: Query Successful, 46 rows returned
22:15:06 Q DBCore: SELECT sln.id, sle.id, slp.x, slp.y, slp.z, slp.x_offset, slp.y_offset, slp.z_offset, slp.heading, sle.spawn_id, sle.spawnpercentage, slp.respawn, slp.grid_id, slp.id, slp.expire_timer, slp.expire_offset FROM spawn_location_placement slp, spawn_location_name sln, spawn_location_entry sle, spawn_signs ss where ss.spawn_id = sle.spawn_id and sln.id = sle.spawn_location_id and sln.id = slp.spawn_location_id and slp.zone_id=34 ORDER BY sln.id, sle.id
22:15:06 D DBCore: Query Successful, 14 rows returned
22:15:06 Q DBCore: SELECT sln.id, sle.id, slp.x, slp.y, slp.z, slp.x_offset, slp.y_offset, slp.z_offset, slp.heading, sle.spawn_id, sle.spawnpercentage, slp.respawn, slp.grid_id, slp.id, slp.expire_timer, slp.expire_offset FROM spawn_location_placement slp, spawn_location_name sln, spawn_location_entry sle, spawn_ground sg where sg.spawn_id = sle.spawn_id and sln.id = sle.spawn_location_id and sln.id = slp.spawn_location_id and slp.zone_id=34 ORDER BY sln.id, sle.id
22:15:06 D DBCore: Query Successful, 1156 rows returned
22:15:06 Q DBCore: SELECT slg.group_id, slg.placement_id, slp.spawn_location_id FROM spawn_location_group slg, spawn_location_placement slp WHERE slg.placement_id = slp.id and slp.zone_id = 34
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT distinct slga.group_id1, slga.group_id2 FROM spawn_location_group_associations slga, spawn_location_group slg, spawn_location_placement slp where (slg.group_id = slga.group_id1 or slg.group_id = slga.group_id2) and slg.placement_id = slp.id and slp.zone_id = 34
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT slgc.group_id, slgc.percentage FROM spawn_location_group_chances slgc, spawn_location_group slg, spawn_location_placement slp where slgc.group_id = slg.group_id and slg.placement_id = slp.id and slp.zone_id = 34
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 I Spawn: Loaded for zone 'Darklight' (34):
        1218 NPC(s), 37 Object(s), 46 Widget(s)
        14 Sign(s), 913 Ground Spawn(s), 0 Spawn Group(s)
        0 Spawn Group Association(s), 0 Spawn Group Chance(s)
22:15:06 Q DBCore: SELECT respawn_zone_id, location_name, safe_x, safe_y, safe_z, heading FROM revive_points where zone_id=34 ORDER BY id asc
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 Q DBCore: SELECT `id`, `grid_id`, `name`, `include_y` FROM `locations` WHERE `zone_id`=34
22:15:06 D DBCore: Query Successful, 0 rows returned
22:15:06 D Client: SendLoginInfo to new client...
22:15:06 D World: Increment Server_Accepted_Connection + 1
22:15:06 D Client: Populate Skill Map...
22:15:06 D Client: Toggle Character Online...
22:15:06 D Player: Toggling Character ONLINE!
22:15:06 Q DBCore: UPDATE characters SET is_online=1 WHERE id = 31;
22:15:06 D DBCore: Query returned no results in DBcore::RunQuery!UPDATE characters SET is_online=1 WHERE id = 31;
22:15:06 D Client: Loading Character Skills for player 'Hhhh'...
22:15:06 Q DBCore: SELECT skill_id, current_val, max_val FROM character_skills, skills where character_skills.skill_id = skills.id and character_skills.char_id = 31
22:15:06 D DBCore: Query Successful, 19 rows returned
22:15:06 T Skills: Loading SkillID: 241174330, cur_val: 1, max_val:
22:15:06 T Skills: Loading SkillID: 366253016, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 418532101, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 540022425, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 609880714, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 613995491, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 723762198, cur_val: 1, max_val:
22:15:06 T Skills: Loading SkillID: 882983852, cur_val: 5, max_val:
22:15:06 T Skills: Loading SkillID: 2246237129, cur_val: 1, max_val:
22:15:07 T Skills: Loading SkillID: 2383540775, cur_val: 5, max_val:
22:15:07 T Skills: Loading SkillID: 2638198038, cur_val: 5, max_val:
22:15:07 T Skills: Loading SkillID: 2741805322, cur_val: 1, max_val:
22:15:07 T Skills: Loading SkillID: 2897193374, cur_val: 1, max_val:
22:15:07 T Skills: Loading SkillID: 3048574950, cur_val: 5, max_val:
22:15:07 T Skills: Loading SkillID: 3421494576, cur_val: 5, max_val:
22:15:07 T Skills: Loading SkillID: 3539032716, cur_val: 1, max_val:
22:15:07 T Skills: Loading SkillID: 3587918036, cur_val: 5, max_val:
22:15:07 T Skills: Loading SkillID: 3809066846, cur_val: 1, max_val:
22:15:07 T Skills: Loading SkillID: 4250045746, cur_val: 5, max_val:
22:15:07 D Titles: Loading Titles for player 'Hhhh'...
22:15:07 Q DBCore: SELECT title_id, title, prefix FROM character_titles, titles WHERE character_titles.title_id = titles.id AND character_titles.char_id = 31
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D Client: No character titles found!
22:15:07 D Client: Initializing starting values - Titles
22:15:07 D Player: Adding default titles for race: 10, class: 9, gender: 1 for char_id: 31
22:15:07 D World: Classes::GetBaseClass returning base class ID: 1
22:15:07 D World: Classes::GetSecondaryBaseClass returning secondary class ID: 8
22:15:07 Q DBCore: INSERT IGNORE INTO character_titles (char_id, title_id) SELECT 31, title_id FROM starting_titles WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255) and gender_id IN (1, 255)
22:15:07 R DBCore: No Result.
22:15:07 D DBCore: Query returned no results in DBcore::RunQuery!INSERT IGNORE INTO character_titles (char_id, title_id) SELECT 31, title_id FROM  starting_titles WHERE class_id IN (1, 8, 9, 255) AND race_id IN (10, 255) and gender_id IN (1, 255)
22:15:07 D Languages: Loading Languages for player 'Hhhh'...
22:15:07 Q DBCore: SELECT language_id, language FROM character_languages, languages WHERE character_languages.language_id = languages.id AND character_languages.char_id = 31
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D Client: No character languages loaded!
22:15:07 D Spells: Loading Character Spells for player Hhhh...
22:15:07 Q DBCore: SELECT spell_id, tier, knowledge_slot, spell_book_type  FROM character_spells, spells where character_spells.spell_id = spells.id and character_spells.char_id = 31 ORDER BY spell_id, tier desc
22:15:07 D DBCore: Query Successful, 12 rows returned
22:15:07 T Spells:      Loading SpellID: 3001, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3004, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3005, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3006, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3007, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3008, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3009, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3015, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3016, tier: 1, slot: 0, type: 2
22:15:07 T Spells:      Loading SpellID: 3101, tier: 1, slot: -1, type: 2
22:15:07 T Spells:      Loading SpellID: 90000, tier: 1, slot: 0, type: 1
22:15:07 T Spells:      Loading SpellID: 90001, tier: 1, slot: 0, type: 0
22:15:07 D Recipes: Loading Character Recipe Books for player 'Hhhh' ...
22:15:07 Q DBCore: SELECT recipebook_id FROM character_recipe_books WHERE char_id = 31
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D Client: No character recipe books found!
22:15:07 D Packet: Sending Login Accepted packet (LS_LoginResponse, 910
22:15:07 Q DBCore: SELECT id, type, spell_id, slot, text_val, hotbar, tier FROM character_skillbar where char_id = 31
22:15:07 D DBCore: Query Successful, 2 rows returned
22:15:07 D World: Send MOTD...
22:15:07 D Packet: Sending Character Macro packet (WS_MacroInit, 910
22:15:07 Q DBCore: SELECT macro_number, macro_name, macro_icon, macro_text FROM character_macros where char_id = 31 ORDER BY macro_number, id
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D World: Sending FriendList...
22:15:07 D Player: Loading Player Factions...
22:15:07 Q DBCore: SELECT faction_id, faction_level FROM character_factions where char_id=31
22:15:07 D DBCore: Query Successful, 5 rows returned
22:15:07 D Player: Loading Character Quests...
22:15:07 Q DBCore: SELECT quest_id, DAY(given_date), MONTH(given_date), YEAR(given_date), DAY(completed_date), MONTH(completed_date), YEAR(completed_date), quest_giver FROM character_quests WHERE char_id=31 ORDER BY current_quest
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D Player: Loading Player Mail...
22:15:07 Q DBCore: SELECT `id`, `player_to_id`, `player_from`, `subject`, `mail_body`, `already_read
`, `mail_type`, `coin_copper`, `coin_silver`, `coin_gold`, `coin_plat`, `stack`, `postage_cost`, `at
tachment_cost`, `char_item_id`, `time_sent`, `expire_time` FROM `character_mail` WHERE `player_to_id
`=31
22:15:07 D DBCore: Query Successful, 0 rows returned
22:15:07 D Client: Send Quest Journal...
   0: 17 00 00 00 FF 14 02 00 - 00 00 00 00 00 00 00 6C  | ...............l
  16: C2 92 28 04 00 48 68 68 - 68 00 00                 | ..(..Hhhh..
22:15:07 D Client: Loading Faction Updates...
22:15:07 D Client: Send Command List...
22:15:07 D Client: Send Language Updates...
22:15:07 D Player: Getting current language for player 'Hhhh'...
22:15:07 Q DBCore: SELECT current_language FROM character_details WHERE char_id = 31
22:15:07 D DBCore: Query Successful, 1 rows returned
22:15:07 D Player:      Language ID: 0Name: num_languages     Index:  0       Type:  int8             Data:  00Array:  Data:Name: unknown   Index:  0       Type:  int8             Data:  00Name: current_language          Index:  0       Type:  int8             Data:  00
22:15:07 Q DBCore: SELECT highest, lowest, zone_name, explored_map_name, unexplored_map_name, bounds1_x, bounds1_z, bounds2_x, bounds2_z, bounds3_x, bounds3_z, bounds4_x, bounds4_z, explored_key, unexplored_key, map_id FROM map_data where zone_name like 'darklight_wood'
22:15:07 D DBCore: Query Successful, 1 rows returned
22:15:07 D Client: SendFriendList
22:15:07 D Client: SendIgnoreList
22:15:07 D Opcode: Opcode 0000 (0): Unknown in ..\..\source\WorldServer\client.cpp
22:15:07 D Opcode: OP_Unknown Received 0026 (38)
22:15:07 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_Unknown'
22:15:07 Q DBCore: replace into variables (variable_name, variable_value) values('gametime', '0/22/3800 12:53')22:15:07 D DBCore: Query returned no results in DBcore::RunQuery!replace into variables (variable_name, variable_value) values('gametime', '0/22/3800 12:53')
22:15:11 D Opcode: Opcode 000D (13): OP_DoneLoadingZoneResourcesMsg
22:15:11 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_DoneLoadingZoneResourcesMsg'
22:15:11 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:11 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:20 I Zone: Initiating zone shutdown of 'TimorousDeep'
22:15:21 I Zone: Completed zone shutdown of 'TimorousDeep'
22:15:35 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 102, 18, 1315372506) ON DUPLICATE KEY UPDATE stat_value = 18, stat_date = 1315372506;
22:15:35 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 102, 18, 1315372506) ON DUPLICATE KEY UPDATE stat_value = 18, stat_date = 1315372506;
22:15:35 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 107, 2, 1315372520) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372520;
22:15:35 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 107, 2, 1315372520) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372520;
22:15:35 Q DBCore: SELECT COUNT(DISTINCT account_id) FROM characters
22:15:35 D DBCore: Query Successful, 1 rows returned
22:15:35 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372535;
22:15:35 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 104, 2, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 2, stat_date = 1315372535;
22:15:35 Q DBCore: SELECT COUNT(id) FROM characters
22:15:35 D DBCore: Query Successful, 1 rows returned
22:15:35 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 7, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 7, stat_date = 1315372535;
22:15:35 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 105, 7, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 7, stat_date = 1315372535;
22:15:35 Q DBCore: SELECT ROUND(AVG(level)) FROM characters
22:15:35 D DBCore: Query Successful, 1 rows returned
22:15:35 Q DBCore: INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372535;
22:15:35 D DBCore: Query returned no results in DBcore::RunQuery!INSERT INTO statistics (char_id, guild_id, stat_id, stat_value, stat_date) VALUES(0, 0, 106, 1, 1315372535) ON DUPLICATE KEY UPDATE stat_value = 1, stat_date = 1315372535;
22:15:38 D Opcode: Opcode 000F (15): OP_DoneLoadingEntityResourcesMsg
22:15:38 D Items: Loading items for character 'Hhhh' (31)
22:15:38 Q DBCore: SELECT type, id, slot, item_id, creator, condition_, attuned, bag_id, count, max_sell_value FROM character_items where char_id = 31 or (bag_id = -4 and account_id = 5636) ORDER BY slot asc
22:15:38 D DBCore: Query Successful, 5 rows returned
22:15:38 D Player: Getting current title index for player 'Hhhh'...
22:15:38 Q DBCore: SELECT prefix_title FROM character_details WHERE char_id = 31
22:15:38 D DBCore: Query Successful, 1 rows returned
22:15:38 D Player:      Prefix Index: -1
22:15:38 D Player: Getting current title index for player 'Hhhh'...
22:15:38 Q DBCore: SELECT suffix_title FROM character_details WHERE char_id = 31
22:15:38 D DBCore: Query Successful, 1 rows returned
22:15:38 D Player:      Suffix Index: -1
22:15:38 D Merchant: Loading Buyback - Player: 31
22:15:38 Q DBCore: SELECT id, item_id, quantity, price FROM character_buyback where char_id = 31 ORDER BY id desc limit 10
22:15:38 D DBCore: Query Successful, 0 rows returned
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_DoneLoadingEntityResourcesMsg'
22:15:38 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:38 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:38 D Opcode: Opcode 00B6 (182): OP_SkillInfoRequest
22:15:38 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SkillInfoRequest'
22:15:39 D Opcode: Opcode 0010 (16): OP_PredictionUpdateMsg
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_PredictionUpdateMsg'
22:15:39 D Opcode: Opcode 0000 (0): Unknown in ..\..\source\WorldServer\client.cpp
22:15:39 D Opcode: OP_Unknown Received 00B2 (178)
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_Unknown'
22:15:39 D Opcode: Opcode 0029 (41): OP_UpdateTargetMsg
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdateTargetMsg'
22:15:39 D Opcode: Opcode 00B5 (181): OP_SignalMsg
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_SignalMsg'
22:15:39 D Opcode: Opcode 0011 (17): OP_RemoteCmdMsg
22:15:39 D Command: Player 'Hhhh' (5636), Command: clearallqueuedabilities
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_RemoteCmdMsg'
22:15:39 D Opcode: Opcode 0011 (17): OP_RemoteCmdMsg
22:15:39 D Command: Handler: 37, COMMAND: 'autoattack'
22:15:39 D Command: Player 'Hhhh' (5636), Command: autoattack
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_RemoteCmdMsg'
22:15:39 D Opcode: Opcode 0011 (17): OP_RemoteCmdMsg
22:15:39 D Command: Handler: 35, COMMAND: 'enablequeuedabilities'
22:15:39 D Command: Player 'Hhhh' (5636), Command: enablequeuedabilities
22:15:39 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_RemoteCmdMsg'
22:15:40 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:40 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:40 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:40 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:41 T Opcode: Opcode 0127 (295): OP_MapFogDataUpdateMsg
22:15:41 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_MapFogDataUpdateMsg'
22:15:42 T Opcode: Opcode 010A (266): OP_KnowledgeWindowSlotMappingMsg
22:15:42 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_KnowledgeWindowSlotMappingMsg'
22:15:48 T Opcode: Opcode 01AD (429): OP_UpdatePositionMsg
22:15:48 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdatePositionMsg'
22:15:58 22:16:36 T Q Opcode: DBCore: Opcode 01AD (429): OP_UpdatePositionMsgSELECT COUNT(DISTINCT account_id) FROM characters
22:16:51 T Client: Func: Client::Process, Line: 1694, Opcode: 'OP_UpdatePositionMsg'
22:16:51 22:16:51 T D Opcode: DBCore: Opcode 01AD (429): OP_UpdatePositionMsgQuery Successful, 1 rows returned

Post by **xinux** » Thu Sep 08, 2011 5:08 pm

Also did a scan and since /exit or force closing the client it usually drops the connection about 15 seconds later and on a camp it's usually 2 minutes later.
They were all pretty much match up till 21:59:56 where i did a /exit with Vvvv and i couldn't find a World: Removing connection... that matched up.

Code: Select all

21:58:10	/camp	tttt		22:00:07
21:59:56	/exit	vvvv		
22:01:32	/zone	vvvv		
22:02:22	/zone	vvvv		
22:02:55	/camp   vvvv		
22:03:45	/exit	tttt		22:03:57
22:06:09	/exit	tttt		22:06:22
22:07:25	/exit	tttt		22:07:37
22:10:20	/camp	tttt		22:10:32  <-- is where i did a camp but it appeared to double save and 
                                           maybe thought i DC'ed?

Post by **Scatman** » Thu Sep 08, 2011 5:49 pm

Well John, the problem is not your logging. World is processing commands just fine. If you put a printf after a /who all command, you'll see it gets printed far before you see it on your client (when you run into the slow processing problem).

I tracked it down to what seems to be a certain situation, one I'm still not sure why it happens. When you see the world processing slow, your client is being slammed by consecutive packets with opcode 9 which is an OP_UNKNOWN. It sends one at a time, about every second when you're standing still.When you begin moving, it's almost as if the packets opcode 9 bombardment gets put on hold until you stop moving again, then it continues. In most cases, if you stand still for a few minutes, it'll stop and your client "catches up". I remember many moons ago, LE mentioned some bug with the packets that were combined, but I can't remember exactly what it was. For some reason I remember this same problem happening when that bug occurred.

It seems I can reproduce this in the following situation and was going to see if anyone else could confirm.
Put your character into a zone with spawns and high activity (I use Ruins).
Start server and client
Log in
(at this point, your client should be OK)
Close server (Leave client open to disconnect and show the login prompt)
Keep the client up
Restart server
Using the client that is already open, re-log in to your server
(Now you should see delays)

See if you guys can reproduce it following those steps so I know i'm just not getting "unlucky".

Post by **John Adams** » Thu Sep 08, 2011 5:52 pm

Freakin awesome troubleshooting, Xinux and Scatman! We got this bug on the run. He's doomed.

I'll try those steps on EQ2TC right now. I'll let you know.

Post by **John Adams** » Thu Sep 08, 2011 6:05 pm

Unfortunately, doing those steps above (Scatman's) my world does appear to still be responding to /who all quickly.

I did get attacked by orcs tho, so I am not sure if that threw off the test. btw, pwned them...

Post by **John Adams** » Sat Sep 10, 2011 9:03 am

Scat, more info for ya.

I have gotten EQ2TC to "lock down" any future connections by simply not connecting properly. Ie., I use a 1096 client to try and log in, and get stuck at the Waiting for Zone Server message. If I "X" out and terminate that client, the next client trying to connect gets the message that the world is not responding.

This is 100% of the time now.

Also, if you disconnect by any other means than a clean /camp, I think we're getting into that state as well.

I have tried stepping through AddAuth, but I cannot see the failure before my client gets disconnected due to timeout.

Furthermore, on the World end, you see the message "Removing connection..." but it never actually removes. 1 Zone(s), 1 Client(s) still connected, long after the 1st client failed to connect.

All you see coming in from new clients is the AddAuth: acct Key: blah, and that's it. We're dead. Going to throw in some debugging and see if I can trace it without having to step into.

Edit: After reverting to 1382, and rebuilding every build upwards through 1414, now doing the same exact steps above that were 100% reproducible -- is now gone. No longer happens, on any rev. Getting so tired of this shit.

Post by **Scatman** » Sat Sep 10, 2011 2:46 pm

Yeah I think it definitely has to do with a fudged up connection. I think that's what I was trying to reproduce on my steps above as well. So you're saying the "bug" was introduced in rev 1414?

Post by **xinux** » Sat Sep 10, 2011 2:50 pm

John Adams wrote:Edit: After reverting to 1382, and rebuilding every build upwards through 1414, now doing the same exact steps above that were 100% reproducible -- is now gone. No longer happens, on any rev. Getting so tired of this shit.

Think he is saying that he cannot reproduce it now.

Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Re: Critical: World slowness, zone & client issues, blah.

Who is online