Super slow loading

Old bugs stored here for reference.
Locked
User avatar
John Adams
Retired
Posts: 9684
Joined: Thu Jul 26, 2007 6:27 am
EQ2Emu Server: EQ2Emulator Test Center
Characters: John
Location: Arizona
Contact:

Super slow loading

Post by John Adams » Wed Feb 03, 2016 2:37 pm

Edit: Moved this to a bug report and posted my entire world console log

Code: Select all

14:23:49 D Login     : Client Data Version: 60114
I know it's been a while since I logged into an eq2emulator server :D but yeah, something is definitely screwy. It took almost 3 minutes just to get through loading 704 NPC spawn data before moving on to objects.

Log:
Module: EQ2EMu WorldServer, Version: 0.7.3-dev

Copyright (C) 2007-2011 EQ2Emulator. http://eq2emulator.net/

EQ2Emulator is free software: you can redistribute it and/or modify
it under the terms of the GNU General Public License as published by
the Free Software Foundation, either version 3 of the License, or
(at your option) any later version.

EQ2Emulator is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

 /$$$$$$$$  /$$$$$$   /$$$$$$  /$$$$$$$$
| $$_____/ /$$__  $$ /$$__  $$| $$_____/
| $$      | $$  \ $$|__/  \ $$| $$       /$$$$$$/$$$$  /$$   /$$
| $$$$$   | $$  | $$  /$$$$$$/| $$$$$   | $$_  $$_  $$| $$  | $$
| $$__/   | $$  | $$ /$$____/ | $$__/   | $$ \ $$ \ $$| $$  | $$
| $$      | $$/$$ $$| $$      | $$      | $$ | $$ | $$| $$  | $$
| $$$$$$$$|  $$$$$$/| $$$$$$$$| $$$$$$$$| $$ | $$ | $$|  $$$$$$/
|________/ \____ $$$|________/|________/|__/ |__/ |__/ \______/
                \__/

 Website     : http://eq2emulator.net
 Forums      : http://eq2emulator.net/phpBB3/
 Contributors: http://eq2emulator.net/wiki/index.php/D ... ntributors
 SVN         : http://svn.eq2emulator.net/svn/eq2server

For more detailed logging, modify 'Level' param the log_config.xml file.

14:18:08 I Init      : Starting EQ2Emulator WorldServer...
14:18:08 I DB        : Using database 'eq2dev' at localhost
14:18:08 D World     : Randomizing World...
14:18:08 D Init      : ./LoginServer.ini read...
14:18:08 I Patcher   : Connecting to DB PatchServer...
14:18:08 D Patcher   : -Connected to Update Server: 127.0.0.1:9103
14:18:08 D Patcher   : -Checking for updates.
14:18:08 D Patcher   : --DB Schema exists! Checking for updates...
14:18:08 D Patcher   : --Max Version: 73017
14:18:08 D Patcher   : --No Table Updates, continuing...
14:18:08 D Patcher   : -No changes to DB Schema...
14:18:08 D Patcher   : -No changes to DB Data...
14:18:08 I Patcher   : DB Update check completed...
14:18:08 I World     : Loading System Data...
14:18:30 I World     : Loaded System Data (took 22 seconds)
14:18:30 W Threaded  : Using Threaded loading of static data...
14:18:30 W Thread    : Item Loading Thread started.
14:18:30 W Thread    : Spell Loading Thread started.
14:18:30 I Guilds    : Loading Guilds...
14:18:30 W Thread    : Achievement Loading Thread started.
14:18:30 I DB        : Using database 'eq2dev' at localhost
14:18:30 I DB        : Using database 'eq2dev' at localhost
14:18:30 I DB        : Using database 'eq2dev' at localhost
14:18:30 I Items     : Loading Items...
14:18:30 I Spells    : Loading Spells...
14:18:30 I Achievements: Loading Achievements...
14:18:31 I Guilds    :  Loaded 3 Guild(s)
14:18:31 I Recipes   : Loading Recipe Books...
14:18:31 D Recipes   :  Loaded 2619 Recipe Books
14:18:31 I Recipes   : Loading Recipes...
14:18:31 D Achievements:        Loaded 1169 achievements
14:18:31 D Achievements:        Loaded 1754 achievement requirements
14:18:31 D Achievements:        Loaded 102 achievement rewards
14:18:31 D Recipes   :  Loaded 981 recipes
14:18:31 I Tradeskills: Loading Tradeskill Events...
14:18:31 D Tradeskills:         Loaded 144 tradeskill events
14:18:31 I AA        : Loading Alternate Advancements...
14:18:31 I AA        : Loaded 3084 Alternate Advancement(s)
14:18:31 I AA        : Loading AA Tree Nodes...
14:18:31 I AA        : Loaded 0 AA Tree Nodes
14:18:31 I Titles    : Loading Titles...
14:18:31 D World     :  Loaded 472 Titles
14:18:31 I Languages : Loading Languages...
14:18:32 D World     :  Loaded 44 Languages
14:18:32 I Chat      : Loading channels...
14:18:32 I LUA       : Loading Spawn Scripts...
14:18:33 D Spells    : Loading Spell Effects...
14:18:35 D LUA       :  Loaded 73954 SpawnScripts
14:18:35 I LUA       : Loading Zone Scripts...
14:18:35 D LUA       :  Loaded 4 ZoneScripts
14:18:35 I World     : Loading House Zone Data...
14:18:35 I World     : Loading Heroic OP Data...
14:18:35 I World     : Loading Race Types Data...
14:18:35 I World     : - Loaded 0 Race Types
14:18:35 I World     : Waiting for load threads to finish.
14:18:35 D Spells    :  Loaded 19602 Spell Effects.
14:18:35 D Spells    : Loading Spell LUA Data...
14:18:38 D Spells    :  Loaded 24409 Spell LUA Data entries.
14:18:38 D Spells    : Loading Spells Scripts...
14:18:52 D Items     :  Loaded 14664 Normal Items
14:18:52 D Items     :  Loaded 4205 Baubles
14:18:52 D Items     :  Loaded 350 Bags
14:18:52 D Items     :  Loaded 537 Books
14:18:52 D Items     :  Loaded 6677 House Items
14:18:52 D Items     :  Loaded 2627 Food Items
14:18:52 D Items     :  Loaded 20459 Weapons
14:18:52 D Items     :  Loaded 3548 Ranged Weapons
14:18:52 D Items     :  Loaded 157 Thrown Weapons
14:18:53 D Items     :  Loaded 62188 Armor Pieces
14:18:53 D Items     :  Loaded 5661 Shields
14:18:54 D Items     :  Loaded 24843 Skill Items
14:18:55 D Items     :  Loaded 25979 Recipe Book Items
14:18:55 D Items     :  Loaded 65 House Containers
14:18:55 D Items     : Loading Item Appearances...
14:18:55 D Items     :  Loaded 73859 Item Appearances
14:18:55 D Items     : Loading Item Stats...
14:19:04 D Items     :  Loaded 451278 Item Stats
14:19:04 D Items     : Loading Item Effects...
14:19:04 D Spells    :  Loaded 13551 SpellScripts
14:19:04 I Spells    : Loaded 11322 Spells (took 34 seconds)
14:19:04 I Spells    : Loading Spell Errors...
14:19:04 I Traits    : Loading Traits...
14:19:04 I Traits    : Loaded 0 Trait(s)
14:19:04 W Thread    : Spell Loading Thread completed.
14:19:13 D Items     :  Loaded 167559 Item Effects
14:19:13 D Items     : Loading Item Level Overrides...
14:19:13 D Items     :  Loaded 0 Item Level Overrides
14:19:13 I Items     : Loaded 153019 Total Items (took 43 seconds)
14:19:13 D Items     : WorldDatabase::LoadNextUniqueItemID: max(id): 256259
14:19:13 I Collect   : Loading Collections...
14:19:13 D Collect   :  Loaded 553 collections
14:19:13 D Collect   :  Loaded 2661 collection items
14:19:13 D Collect   :  Loaded 606 collection rewards
14:19:13 I Merchants : Loading Merchants...
14:19:13 D Merchant  :  Clearing Merchant Inventory...
14:19:13 D Merchant  :  Loading Merchant Inventory...
14:19:13 D Merchant  :  Loaded 22638 Merchant Inventory Item(s)
14:19:13 D Merchant  :  Loaded 774 Merchant List(s)
14:19:13 I Quests    : Loading Quests...
14:19:17 D Quest     :  Loaded 174 Quest(s)
14:19:17 W Thread    : Item Loading Thread completed.
14:19:17 I World     : Load threads finished.
14:19:17 I World     : Total World startup time: 69 seconds.
14:19:17 D World     : Starting factory Reader
14:19:17 D World     : Starting factory Writer
14:19:17 I Net       : World server listening on: 127.0.0.1:9000
14:19:17 I Zone      : Starting static zones...
14:19:17 I IRC       : Starting global IRC server...
14:19:17 D IRC       : Connecting to IRC server irc.eq2emulator.net:6667.
14:19:17 D IRC       : Successfully connected to the global IRC server!
14:19:17 D Thread    : Starting console command thread...
14:19:17 I Console   : Type 'help' or '?' and press enter for menu options.
14:19:17 D Thread    : Starting autoinit loginserver thread...
14:19:17 I World     : Connected to LoginServer: 127.0.0.1: 9100
14:19:18 D Login     : Looking for Login Zone Updates...
14:19:18 D Login     : Looking for Login Appearance Updates...


This was my char create:

14:26:12 D World     : Name check on: Tester
14:26:12 D World     : Response: 1
14:26:12 W World     : New character 'Tester' granted GM status (255) from accountID: 150
14:26:13 D Player    : Adding default zone for race: 9, class: 10 for char_id: 294 (choice: 32)
14:26:13 D Player    : Setting New Character Starting Zone to 'FrostfangSea' FROM starting_zones table.
14:26:13 D Player    : Adding default items for race: 9, class: 10 for char_id: 294
14:26:14 D Player    : Adding default skills for race: 9, class: 10 for char_id: 294
14:26:14 D Player    : Adding default spells for race: 9, class: 10 for char_id: 294
14:26:14 D Player    : Adding default skillbar for race: 9, class: 10 for char_id: 294
14:26:14 D Player    : Adding default titles for race: 9, class: 10, gender: 1 for char_id: 294
14:26:16 D Net       : AddAuth: 150 Key: 1454534776
14:26:18 D Net       : New client from ip: 127.0.0.1 port: 50632
14:26:18 D Net       : Adding new client...
14:26:19 I ZoneAuth  : Access Key: 1454534776, Character Name: Tester, Account ID: 150
14:26:19 D Player    : Loading character for 'Tester' (char_id: 294)
14:26:19 I Zone      : Loading new Zone 'FrostfangSea'
14:26:19 D Zone      : SpawnUpdateTimer: 200ms
14:26:19 D Zone      : SpawnDeleteTimer: 30000ms
14:26:19 D Zone      : Loading zone flight paths
14:26:19 D Zone      : Loaded 0 flight paths for Frostfang Sea
14:26:19 D Zone      : Loaded 0 flight path locations for Frostfang Sea
14:26:19 D Command   : -Loading Entity Commands...
14:26:19 D Player    : Loaded 0 LUA history for Tester
14:26:19 D Recipes   : Loaded 0 recipes for player: Tester (294)
14:26:19 D Achievements: Loaded 0 player achievement updates
14:26:19 D Player    : Loading character_details for 'Tester' (char_id: 294)
14:26:23 D Command   : --Loaded 1315 entity command(s)
14:26:23 I NPC       : -Loading NPC data...
14:27:09 I NPC       : --Loaded 708 NPC(s).
14:27:09 I NPC       : --Loaded 0 NPC Spell(s).
14:27:09 I NPC       : --Loaded 0 NPC Skill(s).
14:27:09 I NPC       : --Loaded 0 NPC Equipment Piece(s).
14:27:48 I NPC       : --Loaded 704 NPC Appearance(s).
14:27:48 I NPC       : --Loaded 614 NPC Equipment Appearance(s).
14:27:48 I NPC       : -Load NPC data complete!
14:27:48 I Object    : -Loading Object data...
14:27:55 D Object    : --Loaded 206 Object(s)
14:27:55 I Object    : -Load Object data complete!
14:27:55 I Sign      : -Loading Sign data...
14:27:57 D Sign      : --Loaded 45 Sign(s)
14:27:57 I Sign      : -Load Sign data complete!
14:27:57 I Widget    : -Loading Widget data...
14:27:59 D Widget    : --Loaded 34 Widget(s)
14:27:59 I Widget    : -Load Widget data complete!
14:27:59 I GSpawn    : -Loading Groundspawn data...
14:28:00 D GSpawn    : --Loaded 19 GroundSpawn(s)
14:28:00 D GSpawn    : --Loaded 30 GroundSpawn Entries.
14:28:01 D GSpawn    : --Loaded 236 GroundSpawn Items.
14:28:01 I GSpawn    : -Load Groundspawn data complete!
14:28:01 I Pet       : -Loading Pet data...
14:28:08 D Pet       : --Loaded 1707 Pet Names
14:28:08 I Pet       : -Load Pet data complete!
14:28:08 I Loot      : -Loading Spawn loot data...
14:28:09 D Loot      : --Loading LootTables...
14:28:09 D Loot      : --Loaded 0 loot tables.
14:28:09 D Loot      : --Loading LootDrops...
14:28:09 D Loot      : --Loaded 0 loot drops.
14:28:09 D Loot      : --Assigning loot table(s) to spawn(s)...
14:28:09 D Loot      : --Loaded 0 spawn loot lists.
14:28:09 I Loot      : -Loading Global loot data...
14:28:09 D Loot      : --Loaded 0 Global loot lists.
14:28:09 I Loot      : -Loading Spawn loot data complete!
14:28:09 I Transport : -Loading Transporters...
14:28:09 D Transport : --Loaded 30 Transporter(s)
14:28:09 D Transport : -Loading Transporter Maps...
14:28:09 D Transport : --Loaded 1 Transporter Maps
14:28:09 I Transport : -Loading Transporters complete!
14:30:23 D World     : Removing connection...


Closed client and logged in again
14:30:58 D Net       : AddAuth: 150 Key: 1454535058
14:30:59 D Net       : New client from ip: 127.0.0.1 port: 50414
14:30:59 D Net       : Adding new client...
14:31:00 I ZoneAuth  : Access Key: 1454535058, Character Name: Tester, Account ID: 150
14:31:00 D Player    : Loading character for 'Tester' (char_id: 294)
14:31:01 D Player    : Loaded 0 LUA history for Tester
14:31:01 D Recipes   : Loaded 0 recipes for player: Tester (294)
14:31:01 D Achievements: Loaded 0 player achievement updates
14:31:01 D Player    : Loading character_details for 'Tester' (char_id: 294)
14:31:01 D Login     : Looking for Login Appearance Updates for char_id: 294
14:31:01 D Login     : Found 5 Login Appearance Updates...
14:31:02 D Login     : Updating `character_items` CRC in WorldDatabase::UpdateLoginEquipment
14:31:03 D Guilds    : Guild Member logged out.
14:31:03 I Zone      : Removing connection for client 'Tester'.
14:31:03 D Player    : Toggling Character OFFLINE!
14:32:29 D World     : Removing connection...


Quit and came crying to the forums


This all happened after I was writing my post

14:34:18 D Login     : Looking for Login Appearance Updates...
14:36:20 I Spawn     : Loaded for zone 'FrostfangSea' (470):
        1806 NPC(s), 1238 Object(s), 34 Widget(s)
        81 Sign(s), 1920 Ground Spawn(s), 1828 Spawn Group(s)
        1164 Spawn Group Association(s), 0 Spawn Group Chance(s)
14:48:04 I Achievements: Achievements loaded (took 1774 seconds)
14:48:04 W Thread    : Achievement Loading Thread completed.
14:48:07 D NPC       : Loaded NPC: 'a portal jumped Ry'Gorr raider' (4700096).
14:48:07 D Client    : SendLoginInfo to new client...
14:48:07 D World     : Increment Server_Accepted_Connection + 1
14:48:07 D Client    : Populate Skill Map...
14:48:08 D Client    : Toggle Character Online...
14:48:08 D Player    : Toggling Character ONLINE!
14:48:08 D Client    : Loading Character Skills for player 'Tester'...
14:48:08 D World     : Loading Titles for player 'Tester'...
14:48:08 D World     : Loading Languages for player 'Tester'...
14:48:08 D Client    : No character languages loaded!
14:48:08 D Spells    : Loading Character Spells for player Tester...
14:48:08 D Recipes   : Loading Character Recipe Books for player 'Tester' ...
14:48:08 D Client    : No character recipe books found!
14:48:08 D Packet    : Sending Login Accepted packet (LS_LoginResponse, 60114)
14:48:08 D World     : Send MOTD...
14:48:08 D Packet    : Sending Character Macro packet (WS_MacroInit, 60114)
14:48:08 D World     : Sending FriendList...
14:48:08 D Player    : Loading Player Factions...
14:48:08 D Player    : Loading Character Quests...
14:48:08 D Player    : Loading Player Mail...
14:48:08 D Client    : Send Quest Journal...
14:48:08 D Client    : Loading Faction Updates...
14:48:08 D Client    : Send Command List...
14:48:08 D Client    : Send Language Updates...
14:48:08 D Player    : Getting current language for player 'Tester'...
14:48:08 D Client    : SendFriendList
14:48:08 D Client    : SendIgnoreList
14:48:08 D Player    : Saving History for Player: 'Tester'
14:48:08 D Player    : Saving LUA History for Player: 'Tester'
14:48:08 D Zone      : Client is disconnecting in ZoneServer::ClientProcess (camping = false)
14:48:08 D CClient   : Client Disconnect...
14:48:08 D Player    : Saving History for Player: 'Tester'
14:48:08 D Player    : Saving LUA History for Player: 'Tester'
14:48:08 D Zone      : Sending login equipment appearance updates...
14:48:08 D Login     : Looking for Login Appearance Updates for char_id: 294
14:48:08 D Guilds    : Guild Member logged out.
14:48:08 D Zone      : Removing client 'Tester' (294) due to LD/Exit...
14:48:08 D Zone      : Calling clients.Remove(client)...
14:48:08 I Zone      : Scheduling client 'Tester' for removal.
14:48:08 D Player    : Toggling Character OFFLINE!
14:48:09 I Zone      : Starting zone shutdown timers...
What's more embarassing is this was on my localhost server, not the public server. Pretty sure I have everything hooked up properly. Although this was the last time I ran my EQ2 emu locally :(

Code: Select all

2014-07-03_eq2world_4028.log
sorry :D I had some free time today and wanted to test my worldwide migrate tool, but I can't get in to verify anything :(

Edit: I didn't realize it wasn't done yet when I first posted this topic, but as I sat here more world loading was continuing on my screen. Very strange, look at the timestamps.

User avatar
John Adams
Retired
Posts: 9684
Joined: Thu Jul 26, 2007 6:27 am
EQ2Emu Server: EQ2Emulator Test Center
Characters: John
Location: Arizona
Contact:

Re: Super slow loading

Post by John Adams » Wed Feb 03, 2016 6:20 pm

Jab, before you spend any time on this, I am pretty sure I am being steamrolled by the Achievements lists. Soon as I nuked those tables, everything seems fine.

Jabantiz
Lead Developer
Posts: 2912
Joined: Wed Jul 25, 2007 2:52 pm
Location: California

Re: Super slow loading

Post by Jabantiz » Wed Feb 03, 2016 6:25 pm

That is really odd, It looks like it took 4 min to load the zone. Also looking at the startup it took 69 seconds for your world to start. From past experience our machines were almost identical and yours always started up slightly faster then mine, just ran mine and it took 36 seconds (x86 debug). Judging by load times it seems to be going extra slow when working with the database, really odd considering how much faster the emu server is then every thing else.

Locked

Who is online

Users browsing this forum: No registered users and 0 guests