EQEmulator Forums

EQEmulator Forums (https://www.eqemulator.org/forums/index.php)
-   Support::Windows Servers (https://www.eqemulator.org/forums/forumdisplay.php?f=587)
-   -   Long #repop and zone times after source upgrade (https://www.eqemulator.org/forums/showthread.php?t=39320)

Akkadius 02-06-2015 05:53 PM

I know you said everything is set to 0, but do you even have quests set to 0?

If you're getting that size of quest messages your file writing is going to slow you down big time

Bohbo 02-06-2015 06:01 PM

Quote:

Originally Posted by Akkadius (Post 237533)
I know you said everything is set to 0, but do you even have quests set to 0?

If you're getting that size of quest messages your file writing is going to slow you down big time

I literally have every field in the log control table set to 0 and restarted the server.

In North Karana I get a 12 sec repop time.

Akkadius 02-06-2015 06:12 PM

Quote:

Originally Posted by Bohbo (Post 237534)
I literally have every field in the log control table set to 0 and restarted the server.

In North Karana I get a 12 sec repop time.

If you are compiling with VS2013 ultimate, you can profile your zone process while you are repopping and figure out what is chewing up CPU cycles by taking so long

Bohbo 02-06-2015 06:55 PM

Quote:

Originally Posted by Akkadius (Post 237535)
If you are compiling with VS2013 ultimate, you can profile your zone process while you are repopping and figure out what is chewing up CPU cycles by taking so long

VS is still installing. Keep in mind all logging is off but it seems like i am getting a hard disk write spike during repop. The spike goes to about 350kb/s not very high but it sustains through the repop. The moment a mob shows up the spike drops. CPU doesn't seem to change.

http://i.imgur.com/SPhLts0.png?1

Akkadius 02-06-2015 07:03 PM

Quote:

Originally Posted by Bohbo (Post 237537)
VS is still installing. Keep in mind all logging is off but it seems like i am getting a hard disk write spike during repop. The spike goes to about 350kb/s not very high but it sustains through the repop. The moment a mob shows up the spike drops. CPU doesn't seem to change.

http://i.imgur.com/SPhLts0.png?1

OK, then what is being written when you open up resource monitor

Bohbo 02-06-2015 07:09 PM

Quote:

Originally Posted by Akkadius (Post 237538)
OK, then what is being written when you open up resource monitor

mysqld.exe is the culprit it looks like. Still trying to write with logging disabled somehow?

Akkadius 02-06-2015 07:12 PM

Quote:

Originally Posted by Bohbo (Post 237539)
mysqld.exe is the culprit it looks like. Still trying to write with logging disabled somehow?

If it is truly mysql, then while you repop do a:

#logs gmsay 36 1

And you can get an idea of what queries are trying to write.

You shouldn't be pushing MB/s of data on write

Bohbo 02-06-2015 07:19 PM

Quote:

Originally Posted by Akkadius (Post 237540)
If it is truly mysql, then while you repop do a:

#logs gmsay 36 1

And you can get an idea of what queries are trying to write.

You shouldn't be pushing MB/s of data on write

Not sure if this matters. But when i tried to use #logs i get the context for the command but if i do #logs gmsay 36 1 i dont get a response and the DB doesn't change. I had to manually change the DB. Any chance that might be related to the cause of problems. I will double check my perl to make sure its the one for plugins.

Akkadius 02-06-2015 07:21 PM

Quote:

Originally Posted by Bohbo (Post 237541)
Not sure if this matters. But when i tried to use #logs i get the context for the command but if i do #logs gmsay 36 1 i dont get a response and the DB doesn't change. I had to manually change the DB. Any chance that might be related to the cause of problems. I will double check my perl to make sure its the one for plugins.

I meant:

#logs set gmsay 36 1

Bohbo 02-06-2015 07:26 PM

Potential problem with Tasks?

Code:

[02-06-2015 :: 15:27:57] [MySQL Query] SELECT `taskid`, `activityid`, `completedtime` FROM `completed_tasks` WHERE `charid` = 8 ORDER BY completedtime, taskid, activityid (0 rows returned)
[02-06-2015 :: 15:27:57] [MySQL Query] SELECT `taskid` FROM character_enabledtasks WHERE `charid` = 8 AND `taskid` >0 AND `taskid` < 10000 ORDER BY `taskid` ASC (0 rows returned)
[02-06-2015 :: 15:28:06] [MySQL Query] SELECT c.id,c.name,c.class,c.level,c.last_login,c.zone_id, g.guild_id,g.rank,g.tribute_enable,g.total_tribute,g.last_tribute, g.banker,g.public_note,g.alt  FROM `character_data` AS c LEFT JOIN guild_members AS g ON c.id=g.char_id  WHERE g.guild_id=1 (6 rows returned)

EDIT:: character_enabledtasks is empty

EDIT2:: Looking at a simple repop SQL seems to be doing about 60 records a second a second on repop

Code:

[02-06-2015 :: 15:41:18] [MySQL Query] DELETE FROM respawn_times WHERE id=9900471 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900471, 1423266078, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900470 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900470, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900469 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900469, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900468 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900468, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900467 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900467, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900466 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900466, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900465 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900465, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900464 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900464, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900463 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900463, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900462 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900462, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900461 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900461, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900460 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900460, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900459 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900459, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900458 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900458, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900457 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900457, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900456 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900456, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900455 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900455, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900454 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900454, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900453 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900453, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] DELETE FROM respawn_times WHERE id=9900452 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:19] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900452, 1423266079, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:20] [MySQL Query] DELETE FROM respawn_times WHERE id=9900451 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:20] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900451, 1423266080, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:20] [MySQL Query] DELETE FROM respawn_times WHERE id=9900447 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:41:20] [MySQL Query] REPLACE INTO respawn_times (id, start, duration, instance_id) VALUES (9900447, 1423266080, 0, 0) (0 rows returned)
[02-06-2015 :: 15:41:31] [MySQL Query] SELECT hotzone FROM zone WHERE short_name = 'freeporttheater' (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT id, spawngroupID, x, y, z, heading, respawntime, variance, pathgrid, _condition, cond_value, enabled, animation FROM spawn2 WHERE zone = 'freeporttheater' AND version = 0 (45 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900447 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900451 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900452 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900453 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900454 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900455 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900456 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900457 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900458 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900459 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900460 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900461 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900462 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900463 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900464 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900465 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900466 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900467 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900468 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900469 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900470 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900471 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900472 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900473 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900474 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900475 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900476 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900478 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900480 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900526 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900593 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900594 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900595 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900596 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900597 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900598 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900599 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900600 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900601 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900602 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900603 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900604 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900605 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900606 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:20] [MySQL Query] SELECT start, duration FROM respawn_times WHERE id = 9900626 AND instance_id = 0 (1 rows returned)
[02-06-2015 :: 15:42:21] [MySQL Query] DELETE FROM respawn_times WHERE id=9900626 AND instance_id = 0 (0 rows returned)
[02-06-2015 :: 15:42:21] [MySQL Query]

EDIT3::Not sure if it matters but i did double check perl and the #logs set gmsay 36 <1/0> gives feedback for enabling or disabling but doesn't actually change the DB.

Cassieze 02-06-2015 07:59 PM

Could this have something to do with xampp versus installing mysql standalone? I know on my old comp I never had this issue either. But now on the a fresh install of everything on my new pc, its taking 21-25 seconds to perform #repop

Bohbo 02-06-2015 08:01 PM

Quote:

Originally Posted by Cassieze (Post 237545)
Could this have something to do with xampp versus installing mysql standalone? I know on my old comp I never had this issue either. But now on the a fresh install of everything on my new pc, its taking 21-25 seconds to perform #repop

*highfive* brother we aren't alone!~ I did install XAMP but i skipped mysql and used mariadb10.0 instead

I will mess around with XAMPP and see if anything might be messing it up

EDIT:: Then again maybe not.
http://i.imgur.com/SgTYBPa.png

Bohbo 02-06-2015 08:22 PM

@Akka

I am setting up a fresh W8.1 Box on a XEON 4gb machine Let me know if there is anything outside of the normal windows server install setup guide you want me to do.

Akkadius 02-06-2015 09:27 PM

You've never really said anything about what your using for disks, since I got home and was able to check I could see my writes were happening like that because its DELETING and REPLACE INTO constantly which is kind of horrid.

I have a M.2 SSD so my read speads are up 1000MB + and latency is nuts, so my repop's are pretty quick.

But, since repops happen potentially hundreds of times during the developing process, I'm going to look at getting them sped up quite a bit by optimizing the database end. I think everyone would appreciate this as a quality of life enhancement.

Akkadius 02-06-2015 09:30 PM

I will also make note that if you are using windows and you have any logs to 'console' enabled for MYSQL queries, that will definitely slow things down. Same thing for Perl, outputting to windows console is really slow.

If you have a shit load of quest errors like you posted before, and they are going to windows console, that is your problem.

Everything that we have enabled by default going to console is usually used sparingly given the cost consideration of windows console being slow.

If you want to see quests errors, I would highly recommend using gmsay because that is going to be a much faster medium to see realtime than the console


All times are GMT -4. The time now is 01:22 AM.

Powered by vBulletin®, Copyright ©2000 - 2025, Jelsoft Enterprises Ltd.