Core/Metric: Add more metrics about World::Update() loop (#25098)

* Core/Metric: Add more metrics about World::Update() loop

* Add new Performance profiling grafana dashboard

* Add new cmake setting WITHOUT_METRICS that disables all metrics

As new metrics are added, someone might want to disable them if unused.

* Add more metrics about World::Update() loop

* Remove old performance profiling features

Remove "server set difftime" command, "-RecordUpdateTimeDiffInterval" and "MinRecordUpdateTimeDiff" worldserver config settings and their related code.
The whole UpdateTime class could be removed too.

* Update and rename 2020_07_99_99_world.sql to 2020_07_24_00_world.sql

(cherry picked from commit 3c0ac7302f)
This commit is contained in:
Giacomo Pozzoni
2020-07-23 22:30:16 +00:00
committed by Shauren
parent 1dfcb7086e
commit e8583d04f6
12 changed files with 974 additions and 153 deletions

View File

@@ -49,6 +49,7 @@ endif()
option(WITH_WARNINGS "Show all warnings during compile" 0)
option(WITH_COREDEBUG "Include additional debug-code in core" 0)
option(WITH_STRICT_DATABASE_TYPE_CHECKS "Enable strict checking of database field value accessors" 0)
option(WITHOUT_METRICS "Disable metrics reporting (i.e. InfluxDB and Grafana)" 0)
option(COPY_CONF "Copy authserver and worldserver .conf.dist files to the project dir" 1)
set(WITH_SOURCE_TREE "hierarchical" CACHE STRING "Build the source tree for IDE's.")
set_property(CACHE WITH_SOURCE_TREE PROPERTY STRINGS no flat hierarchical hierarchical-folders)

View File

@@ -143,6 +143,13 @@ if(PERFORMANCE_PROFILING)
add_definitions(-DPERFORMANCE_PROFILING)
endif()
if(WITHOUT_METRICS)
message("")
message(" *** WITHOUT_METRICS - WARNING!")
message(" *** Please note that this will disable all metrics output (i.e. InfluxDB and Grafana)")
add_definitions(-DWITHOUT_METRICS)
endif()
if(WITH_STRICT_DATABASE_TYPE_CHECKS)
message("")
message(" *** WITH_STRICT_DATABASE_TYPE_CHECKS - WARNING!")

View File

@@ -0,0 +1,854 @@
{
"annotations": {
"list": [
{
"builtIn": 1,
"datasource": "-- Grafana --",
"enable": true,
"hide": true,
"iconColor": "rgba(0, 211, 255, 1)",
"name": "Annotations & Alerts",
"type": "dashboard"
},
{
"datasource": "Influx",
"enable": true,
"hide": false,
"iconColor": "#c0c6be",
"limit": 100,
"name": "Global Events",
"query": "select title, text from events where $timeFilter and realm =~ /$realm$/",
"showIn": 0,
"tags": [],
"textColumn": "text",
"type": "tags"
}
]
},
"editable": true,
"gnetId": null,
"graphTooltip": 0,
"id": 15,
"iteration": 1595439203259,
"links": [],
"panels": [
{
"aliasColors": {},
"bars": false,
"dashLength": 10,
"dashes": false,
"datasource": "Influx",
"editable": true,
"error": false,
"fieldConfig": {
"defaults": {
"custom": {}
},
"overrides": []
},
"fill": 1,
"fillGradient": 0,
"grid": {
"leftLogBase": 1,
"leftMax": null,
"leftMin": null,
"rightLogBase": 1,
"rightMax": null,
"rightMin": null
},
"gridPos": {
"h": 7,
"w": 24,
"x": 0,
"y": 0
},
"hiddenSeries": false,
"id": 4,
"isNew": true,
"legend": {
"avg": false,
"current": false,
"max": false,
"min": false,
"show": true,
"total": false,
"values": false
},
"lines": true,
"linewidth": 2,
"links": [],
"nullPointMode": "connected",
"options": {
"dataLinks": []
},
"percentage": false,
"pointradius": 5,
"points": false,
"renderer": "flot",
"seriesOverrides": [],
"spaceLength": 10,
"stack": false,
"steppedLine": false,
"targets": [
{
"alias": "Update diff",
"dsType": "influxdb",
"groupBy": [
{
"params": [
"$interval"
],
"type": "time"
},
{
"params": [
"null"
],
"type": "fill"
}
],
"measurement": "update_time_diff",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"update_time_diff\" WHERE (\"realm\" =~ /$realm$/) AND $timeFilter GROUP BY time($interval) fill(null)",
"rawQuery": false,
"refId": "A",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/$realm$/"
}
]
}
],
"thresholds": [],
"timeFrom": null,
"timeRegions": [],
"timeShift": null,
"title": "Update diff",
"tooltip": {
"msResolution": false,
"shared": true,
"sort": 0,
"value_type": "cumulative"
},
"type": "graph",
"x-axis": true,
"xaxis": {
"buckets": null,
"mode": "time",
"name": null,
"show": true,
"values": []
},
"y-axis": true,
"y_formats": [
"ms",
"short"
],
"yaxes": [
{
"format": "ms",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
},
{
"format": "short",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
}
],
"yaxis": {
"align": false,
"alignLevel": null
}
},
{
"aliasColors": {},
"bars": false,
"dashLength": 10,
"dashes": false,
"datasource": null,
"fieldConfig": {
"defaults": {
"custom": {}
},
"overrides": []
},
"fill": 1,
"fillGradient": 0,
"gridPos": {
"h": 8,
"w": 12,
"x": 0,
"y": 7
},
"hiddenSeries": false,
"id": 6,
"legend": {
"avg": false,
"current": false,
"hideEmpty": false,
"hideZero": true,
"max": false,
"min": false,
"show": true,
"total": false,
"values": false
},
"lines": true,
"linewidth": 2,
"nullPointMode": "connected",
"options": {
"dataLinks": []
},
"percentage": false,
"pointradius": 2,
"points": false,
"renderer": "flot",
"seriesOverrides": [],
"spaceLength": 10,
"stack": false,
"steppedLine": false,
"targets": [
{
"alias": "Total",
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"none"
],
"type": "fill"
}
],
"measurement": "world_update_time_total",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"map_update_time_diff\" WHERE (\"realm\" =~ /^$realm$/) AND $timeFilter GROUP BY time($__interval), \"map_id\" fill(none)",
"rawQuery": false,
"refId": "B",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/^$realm$/"
}
]
},
{
"alias": "$tag_type",
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"type"
],
"type": "tag"
},
{
"params": [
"none"
],
"type": "fill"
}
],
"measurement": "world_update_time",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"map_update_time_diff\" WHERE (\"realm\" =~ /^$realm$/) AND $timeFilter GROUP BY time($__interval), \"map_id\" fill(none)",
"rawQuery": false,
"refId": "C",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/^$realm$/"
}
]
}
],
"thresholds": [],
"timeFrom": null,
"timeRegions": [],
"timeShift": null,
"title": "World Update - Split",
"tooltip": {
"shared": true,
"sort": 0,
"value_type": "individual"
},
"type": "graph",
"xaxis": {
"buckets": null,
"mode": "time",
"name": null,
"show": true,
"values": []
},
"yaxes": [
{
"format": "ms",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
},
{
"format": "short",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
}
],
"yaxis": {
"align": false,
"alignLevel": null
}
},
{
"aliasColors": {},
"bars": false,
"dashLength": 10,
"dashes": false,
"datasource": null,
"fieldConfig": {
"defaults": {
"custom": {}
},
"overrides": []
},
"fill": 10,
"fillGradient": 0,
"gridPos": {
"h": 8,
"w": 12,
"x": 12,
"y": 7
},
"hiddenSeries": false,
"id": 7,
"legend": {
"avg": false,
"current": false,
"hideEmpty": false,
"hideZero": true,
"max": false,
"min": false,
"show": true,
"total": false,
"values": false
},
"lines": true,
"linewidth": 0,
"nullPointMode": "connected",
"options": {
"dataLinks": []
},
"percentage": false,
"pointradius": 2,
"points": false,
"renderer": "flot",
"seriesOverrides": [],
"spaceLength": 10,
"stack": true,
"steppedLine": false,
"targets": [
{
"alias": "$tag_type",
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"type"
],
"type": "tag"
},
{
"params": [
"none"
],
"type": "fill"
}
],
"measurement": "world_update_time",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"map_update_time_diff\" WHERE (\"realm\" =~ /^$realm$/) AND $timeFilter GROUP BY time($__interval), \"map_id\" fill(none)",
"rawQuery": false,
"refId": "C",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/^$realm$/"
}
]
}
],
"thresholds": [],
"timeFrom": null,
"timeRegions": [],
"timeShift": null,
"title": "World Update - Stacked",
"tooltip": {
"shared": true,
"sort": 0,
"value_type": "individual"
},
"type": "graph",
"xaxis": {
"buckets": null,
"mode": "time",
"name": null,
"show": true,
"values": []
},
"yaxes": [
{
"format": "ms",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
},
{
"format": "short",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
}
],
"yaxis": {
"align": false,
"alignLevel": null
}
},
{
"aliasColors": {},
"bars": false,
"dashLength": 10,
"dashes": false,
"datasource": null,
"fieldConfig": {
"defaults": {
"custom": {}
},
"overrides": []
},
"fill": 1,
"fillGradient": 0,
"gridPos": {
"h": 8,
"w": 12,
"x": 0,
"y": 15
},
"hiddenSeries": false,
"id": 2,
"legend": {
"avg": false,
"current": false,
"hideEmpty": false,
"hideZero": true,
"max": false,
"min": false,
"show": true,
"total": false,
"values": false
},
"lines": true,
"linewidth": 2,
"nullPointMode": "connected",
"options": {
"dataLinks": []
},
"percentage": false,
"pointradius": 2,
"points": false,
"renderer": "flot",
"seriesOverrides": [],
"spaceLength": 10,
"stack": false,
"steppedLine": false,
"targets": [
{
"alias": "Map $tag_map_id",
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"map_id"
],
"type": "tag"
},
{
"params": [
"none"
],
"type": "fill"
}
],
"measurement": "map_update_time_diff",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"map_update_time_diff\" WHERE (\"realm\" =~ /^$realm$/) AND $timeFilter GROUP BY time($__interval), \"map_id\" fill(none)",
"rawQuery": false,
"refId": "A",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/^$realm$/"
}
]
}
],
"thresholds": [],
"timeFrom": null,
"timeRegions": [],
"timeShift": null,
"title": "Map update - Split",
"tooltip": {
"shared": true,
"sort": 0,
"value_type": "individual"
},
"type": "graph",
"xaxis": {
"buckets": null,
"mode": "time",
"name": null,
"show": true,
"values": []
},
"yaxes": [
{
"format": "ms",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
},
{
"format": "short",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
}
],
"yaxis": {
"align": false,
"alignLevel": null
}
},
{
"aliasColors": {},
"bars": false,
"dashLength": 10,
"dashes": false,
"datasource": null,
"fieldConfig": {
"defaults": {
"custom": {}
},
"overrides": []
},
"fill": 10,
"fillGradient": 0,
"gridPos": {
"h": 8,
"w": 12,
"x": 12,
"y": 15
},
"hiddenSeries": false,
"id": 5,
"legend": {
"alignAsTable": false,
"avg": false,
"current": false,
"hideEmpty": false,
"hideZero": true,
"max": false,
"min": false,
"show": true,
"total": false,
"values": false
},
"lines": true,
"linewidth": 0,
"nullPointMode": "connected",
"options": {
"dataLinks": []
},
"percentage": false,
"pointradius": 2,
"points": false,
"renderer": "flot",
"seriesOverrides": [],
"spaceLength": 10,
"stack": true,
"steppedLine": false,
"targets": [
{
"alias": "Map $tag_map_id",
"groupBy": [
{
"params": [
"$__interval"
],
"type": "time"
},
{
"params": [
"map_id"
],
"type": "tag"
},
{
"params": [
"none"
],
"type": "fill"
}
],
"measurement": "map_update_time_diff",
"orderByTime": "ASC",
"policy": "default",
"query": "SELECT max(\"value\") FROM \"map_update_time_diff\" WHERE (\"realm\" =~ /^$realm$/) AND $timeFilter GROUP BY time($__interval), \"map_id\" fill(none)",
"rawQuery": false,
"refId": "A",
"resultFormat": "time_series",
"select": [
[
{
"params": [
"value"
],
"type": "field"
},
{
"params": [],
"type": "max"
}
]
],
"tags": [
{
"key": "realm",
"operator": "=~",
"value": "/^$realm$/"
}
]
}
],
"thresholds": [],
"timeFrom": null,
"timeRegions": [],
"timeShift": null,
"title": "Map update - Stacked",
"tooltip": {
"shared": true,
"sort": 0,
"value_type": "individual"
},
"type": "graph",
"xaxis": {
"buckets": null,
"mode": "time",
"name": null,
"show": true,
"values": []
},
"yaxes": [
{
"format": "ms",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
},
{
"format": "short",
"label": null,
"logBase": 1,
"max": null,
"min": null,
"show": true
}
],
"yaxis": {
"align": false,
"alignLevel": null
}
}
],
"refresh": "1m",
"schemaVersion": 25,
"style": "dark",
"tags": [],
"templating": {
"list": [
{
"allValue": null,
"current": {
"selected": true,
"text": "Trinity",
"value": "Trinity"
},
"datasource": "Influx",
"definition": "show tag values from events with key = realm",
"hide": 0,
"includeAll": false,
"label": null,
"multi": false,
"name": "realm",
"options": [],
"query": "show tag values from events with key = realm",
"refresh": 1,
"regex": "",
"skipUrlSync": false,
"sort": 0,
"tagValuesQuery": "",
"tags": [],
"tagsQuery": "",
"type": "query",
"useTags": false
}
]
},
"time": {
"from": "now-6h",
"to": "now"
},
"timepicker": {
"refresh_intervals": [
"10s",
"30s",
"1m",
"5m",
"15m",
"30m",
"1h",
"2h",
"1d"
]
},
"timezone": "",
"title": "Performance profiling",
"uid": "IRRL03nMk",
"version": 1
}

View File

@@ -0,0 +1,2 @@
--
DELETE FROM command WHERE NAME = 'server set difftime';

View File

@@ -137,7 +137,7 @@ void Metric::SendBatch()
batchedData << ",realm=" << _realmName;
for (MetricTag const& tag : data->Tags)
batchedData << "," << tag.first << "=" << tag.second;
batchedData << "," << tag.first << "=" << FormatInfluxDBTagValue(tag.second);
batchedData << " ";

View File

@@ -158,21 +158,27 @@ MetricStopWatch<LoggerType> MakeMetricStopWatch(LoggerType&& loggerFunc)
#define TC_METRIC_TAG(name, value) { name, value }
#ifdef PERFORMANCE_PROFILING
#define TC_METRIC_DO_CONCAT(a, b) a##b
#define TC_METRIC_CONCAT(a, b) TC_METRIC_DO_CONCAT(a, b)
#define TC_METRIC_UNIQUE_NAME(name) TC_METRIC_CONCAT(name, __LINE__)
#if defined PERFORMANCE_PROFILING || defined WITHOUT_METRICS
#define TC_METRIC_EVENT(category, title, description) ((void)0)
#define TC_METRIC_VALUE(category, value) ((void)0)
#elif TRINITY_PLATFORM != TRINITY_PLATFORM_WINDOWS
#define TC_METRIC_EVENT(category, title, description) \
do { \
if (sMetric->IsEnabled()) \
sMetric->LogEvent(category, title, description); \
} while (0)
#define TC_METRIC_VALUE(category, value, ...) \
do { \
if (sMetric->IsEnabled()) \
sMetric->LogValue(category, value, { __VA_ARGS__ }); \
} while (0)
#define TC_METRIC_TIMER(category, ...) ((void)0)
#else
# if TRINITY_PLATFORM != TRINITY_PLATFORM_WINDOWS
#define TC_METRIC_EVENT(category, title, description) \
do { \
if (sMetric->IsEnabled()) \
sMetric->LogEvent(category, title, description); \
} while (0)
#define TC_METRIC_VALUE(category, value, ...) \
do { \
if (sMetric->IsEnabled()) \
sMetric->LogValue(category, value, { __VA_ARGS__ }); \
} while (0)
# else
#define TC_METRIC_EVENT(category, title, description) \
__pragma(warning(push)) \
__pragma(warning(disable:4127)) \
@@ -189,11 +195,12 @@ MetricStopWatch<LoggerType> MakeMetricStopWatch(LoggerType&& loggerFunc)
sMetric->LogValue(category, value, { __VA_ARGS__ }); \
} while (0) \
__pragma(warning(pop))
#endif
# endif
#define TC_METRIC_TIMER(category, ...) \
MetricStopWatch __tc_metric_stop_watch = MakeMetricStopWatch([&](TimePoint start) \
MetricStopWatch TC_METRIC_UNIQUE_NAME(__tc_metric_stop_watch) = MakeMetricStopWatch([&](TimePoint start) \
{ \
sMetric->LogValue(category, std::chrono::steady_clock::now() - start, { __VA_ARGS__ }); \
});
#endif
#endif // METRIC_H__

View File

@@ -636,7 +636,7 @@ enum RBACPermissions
RBAC_PERM_COMMAND_SERVER_RESTART_CANCEL = 728,
RBAC_PERM_COMMAND_SERVER_SET = 729,
RBAC_PERM_COMMAND_SERVER_SET_CLOSED = 730,
RBAC_PERM_COMMAND_SERVER_SET_DIFFTIME = 731,
RBAC_PERM_COMMAND_SERVER_SET_DIFFTIME = 731, // reserved
RBAC_PERM_COMMAND_SERVER_SET_LOGLEVEL = 732,
RBAC_PERM_COMMAND_SERVER_SET_MOTD = 733,
RBAC_PERM_COMMAND_SERVER_SHUTDOWN = 734,

View File

@@ -31,7 +31,6 @@ UpdateTime::UpdateTime()
_maxUpdateTime = 0;
_maxUpdateTimeOfLastTable = 0;
_maxUpdateTimeOfCurrentTable = 0;
_recordedTime = 0;
_updateTimeDataTable = { };
}
@@ -92,47 +91,3 @@ void UpdateTime::UpdateWithDiff(uint32 diff)
else if (_updateTimeTableIndex)
_averageUpdateTime = _totalUpdateTime / _updateTimeTableIndex;
}
void UpdateTime::RecordUpdateTimeReset()
{
_recordedTime = getMSTime();
}
void UpdateTime::_RecordUpdateTimeDuration(std::string const& text, uint32 minUpdateTime)
{
uint32 thisTime = getMSTime();
uint32 diff = getMSTimeDiff(_recordedTime, thisTime);
if (diff > minUpdateTime)
TC_LOG_INFO("misc", "Recored Update Time of %s: %u.", text.c_str(), diff);
_recordedTime = thisTime;
}
void WorldUpdateTime::LoadFromConfig()
{
_recordUpdateTimeInverval = sConfigMgr->GetIntDefault("RecordUpdateTimeDiffInterval", 60000);
_recordUpdateTimeMin = sConfigMgr->GetIntDefault("MinRecordUpdateTimeDiff", 100);
}
void WorldUpdateTime::SetRecordUpdateTimeInterval(uint32 t)
{
_recordUpdateTimeInverval = t;
}
void WorldUpdateTime::RecordUpdateTime(uint32 gameTimeMs, uint32 diff, uint32 sessionCount)
{
if (_recordUpdateTimeInverval > 0 && diff > _recordUpdateTimeMin)
{
if (getMSTimeDiff(_lastRecordTime, gameTimeMs) > _recordUpdateTimeInverval)
{
TC_LOG_DEBUG("misc", "Update time diff: %u. Players online: %u.", GetAverageUpdateTime(), sessionCount);
_lastRecordTime = gameTimeMs;
}
}
}
void WorldUpdateTime::RecordUpdateTimeDuration(std::string const& text)
{
_RecordUpdateTimeDuration(text, _recordUpdateTimeMin);
}

View File

@@ -37,13 +37,9 @@ class TC_GAME_API UpdateTime
void UpdateWithDiff(uint32 diff);
void RecordUpdateTimeReset();
protected:
UpdateTime();
void _RecordUpdateTimeDuration(std::string const& text, uint32 minUpdateTime);
private:
DiffTableArray _updateTimeDataTable;
uint32 _averageUpdateTime;
@@ -52,23 +48,12 @@ class TC_GAME_API UpdateTime
uint32 _maxUpdateTime;
uint32 _maxUpdateTimeOfLastTable;
uint32 _maxUpdateTimeOfCurrentTable;
uint32 _recordedTime;
};
class TC_GAME_API WorldUpdateTime : public UpdateTime
{
public:
WorldUpdateTime() : UpdateTime(), _recordUpdateTimeInverval(0), _recordUpdateTimeMin(0), _lastRecordTime(0) { }
void LoadFromConfig();
void SetRecordUpdateTimeInterval(uint32 t);
void RecordUpdateTime(uint32 gameTimeMs, uint32 diff, uint32 sessionCount);
void RecordUpdateTimeDuration(std::string const& text);
private:
uint32 _recordUpdateTimeInverval;
uint32 _recordUpdateTimeMin;
uint32 _lastRecordTime;
WorldUpdateTime() : UpdateTime() { }
};
TC_GAME_API extern WorldUpdateTime sWorldUpdateTime;

View File

@@ -554,9 +554,6 @@ void World::LoadConfigSettings(bool reload)
TC_LOG_INFO("server.loading", "Using %s DBC Locale", localeNames[m_defaultDbcLocale]);
// load update time related configs
sWorldUpdateTime.LoadFromConfig();
///- Read the player limit and the Message of the day from the config file
SetPlayerAmountLimit(sConfigMgr->GetIntDefault("PlayerLimit", 100));
SetMotd(sConfigMgr->GetStringDefault("Motd", "Welcome to a Trinity Core Server."));
@@ -2511,15 +2508,13 @@ void World::LoadAutobroadcasts()
/// Update the World !
void World::Update(uint32 diff)
{
TC_METRIC_TIMER("world_update_time_total");
///- Update the game time and check for shutdown time
_UpdateGameTime();
time_t currentGameTime = GameTime::GetGameTime();
sWorldUpdateTime.UpdateWithDiff(diff);
// Record update if recording set in log and diff is greater then minimum set in log
sWorldUpdateTime.RecordUpdateTime(GameTime::GetGameTimeMS(), diff, GetActiveSessionCount());
///- Update the different timers
for (int i = 0; i < WUPDATE_COUNT; ++i)
{
@@ -2532,6 +2527,7 @@ void World::Update(uint32 diff)
///- Update Who List Storage
if (m_timers[WUPDATE_WHO_LIST].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update who list"));
m_timers[WUPDATE_WHO_LIST].Reset();
sWhoListStorageMgr->Update();
}
@@ -2542,6 +2538,7 @@ void World::Update(uint32 diff)
if (sWorld->getBoolConfig(CONFIG_PRESERVE_CUSTOM_CHANNELS))
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Save custom channels"));
ChannelMgr* mgr1 = ASSERT_NOTNULL(ChannelMgr::ForTeam(ALLIANCE));
mgr1->SaveToDB();
ChannelMgr* mgr2 = ASSERT_NOTNULL(ChannelMgr::ForTeam(HORDE));
@@ -2550,23 +2547,39 @@ void World::Update(uint32 diff)
}
}
CheckScheduledResetTimes();
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Check daily reset times"));
CheckScheduledResetTimes();
}
if (currentGameTime > m_NextRandomBGReset)
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Reset random BG"));
ResetRandomBG();
}
if (currentGameTime > m_NextCalendarOldEventsDeletionTime)
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Delete old calendar events"));
CalendarDeleteOldEvents();
}
if (currentGameTime > m_NextGuildReset)
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Reset guild cap"));
ResetGuildCap();
}
if (currentGameTime > m_NextCurrencyReset)
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Reset currency weekly cap"));
ResetCurrencyWeekCap();
}
/// <ul><li> Handle auctions when the timer has passed
if (m_timers[WUPDATE_AUCTIONS].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update expired auctions"));
m_timers[WUPDATE_AUCTIONS].Reset();
///- Update mails (return old mails with item, or delete them)
@@ -2583,6 +2596,7 @@ void World::Update(uint32 diff)
if (m_timers[WUPDATE_AUCTIONS_PENDING].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update pending auctions"));
m_timers[WUPDATE_AUCTIONS_PENDING].Reset();
sAuctionMgr->UpdatePendingAuctions();
@@ -2590,6 +2604,7 @@ void World::Update(uint32 diff)
if (m_timers[WUPDATE_BLACKMARKET].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update pending black market auctions"));
m_timers[WUPDATE_BLACKMARKET].Reset();
///- Update blackmarket, refresh auctions if necessary
@@ -2610,6 +2625,7 @@ void World::Update(uint32 diff)
/// <li> Handle AHBot operations
if (m_timers[WUPDATE_AHBOT].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update AHBot"));
sAuctionBot->Update();
m_timers[WUPDATE_AHBOT].Reset();
}
@@ -2620,18 +2636,21 @@ void World::Update(uint32 diff)
/// <li> Handle file changes
if (m_timers[WUPDATE_CHECK_FILECHANGES].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update HotSwap"));
sScriptReloadMgr->Update();
m_timers[WUPDATE_CHECK_FILECHANGES].Reset();
}
/// <li> Handle session updates when the timer has passed
sWorldUpdateTime.RecordUpdateTimeReset();
UpdateSessions(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateSessions");
{
/// <li> Handle session updates when the timer has passed
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update sessions"));
UpdateSessions(diff);
}
/// <li> Update uptime table
if (m_timers[WUPDATE_UPTIME].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update uptime"));
uint32 tmpDiff = GameTime::GetUptime();
uint32 maxOnlinePlayers = GetMaxPlayerCount();
@@ -2652,6 +2671,7 @@ void World::Update(uint32 diff)
{
if (m_timers[WUPDATE_CLEANDB].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Clean logs table"));
m_timers[WUPDATE_CLEANDB].Reset();
LoginDatabasePreparedStatement* stmt = LoginDatabase.GetPreparedStatement(LOGIN_DEL_OLD_LOGS);
@@ -2666,51 +2686,64 @@ void World::Update(uint32 diff)
/// <li> Handle all other objects
///- Update objects when the timer has passed (maps, transport, creatures, ...)
sWorldUpdateTime.RecordUpdateTimeReset();
sMapMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateMapMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update maps"));
sMapMgr->Update(diff);
}
if (sWorld->getBoolConfig(CONFIG_AUTOBROADCAST))
{
if (m_timers[WUPDATE_AUTOBROADCAST].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Send autobroadcast"));
m_timers[WUPDATE_AUTOBROADCAST].Reset();
SendAutoBroadcast();
}
}
sBattlegroundMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateBattlegroundMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update battlegrounds"));
sBattlegroundMgr->Update(diff);
}
sOutdoorPvPMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateOutdoorPvPMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update outdoor pvp"));
sOutdoorPvPMgr->Update(diff);
}
sBattlefieldMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("BattlefieldMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update battlefields"));
sBattlefieldMgr->Update(diff);
}
///- Delete all characters which have been deleted X days before
if (m_timers[WUPDATE_DELETECHARS].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Delete old characters"));
m_timers[WUPDATE_DELETECHARS].Reset();
Player::DeleteOldCharacters();
}
sGroupMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateGroupMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update groups"));
sGroupMgr->Update(diff);
}
sLFGMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("UpdateLFGMgr");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update LFG"));
sLFGMgr->Update(diff);
}
sGroupMgr->Update(diff);
sWorldUpdateTime.RecordUpdateTimeDuration("GroupMgr");
// execute callbacks from sql queries that were queued recently
ProcessQueryCallbacks();
sWorldUpdateTime.RecordUpdateTimeDuration("ProcessQueryCallbacks");
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Process query callbacks"));
// execute callbacks from sql queries that were queued recently
ProcessQueryCallbacks();
}
///- Erase corpses once every 20 minutes
if (m_timers[WUPDATE_CORPSES].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Remove old corpses"));
m_timers[WUPDATE_CORPSES].Reset();
sMapMgr->DoForAllMaps([](Map* map)
{
@@ -2721,6 +2754,7 @@ void World::Update(uint32 diff)
///- Process Game events when necessary
if (m_timers[WUPDATE_EVENTS].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update game events"));
m_timers[WUPDATE_EVENTS].Reset(); // to give time for Update() to be processed
uint32 nextGameEvent = sGameEventMgr->Update();
m_timers[WUPDATE_EVENTS].SetInterval(nextGameEvent);
@@ -2730,6 +2764,7 @@ void World::Update(uint32 diff)
///- Ping to keep MySQL connections alive
if (m_timers[WUPDATE_PINGDB].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Ping MySQL"));
m_timers[WUPDATE_PINGDB].Reset();
TC_LOG_DEBUG("misc", "Ping MySQL to keep connection alive");
CharacterDatabase.KeepAlive();
@@ -2739,12 +2774,16 @@ void World::Update(uint32 diff)
if (m_timers[WUPDATE_GUILDSAVE].Passed())
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Save guilds"));
m_timers[WUPDATE_GUILDSAVE].Reset();
sGuildMgr->SaveGuilds();
}
// update the instance reset times
sInstanceSaveMgr->Update();
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update instance reset times"));
// update the instance reset times
sInstanceSaveMgr->Update();
}
// Check for shutdown warning
if (_guidWarn && !_guidAlert)
@@ -2756,14 +2795,23 @@ void World::Update(uint32 diff)
SendGuidWarning();
}
// And last, but not least handle the issued cli commands
ProcessCliCommands();
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Process cli commands"));
// And last, but not least handle the issued cli commands
ProcessCliCommands();
}
sScriptMgr->OnWorldUpdate(diff);
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update world scripts"));
sScriptMgr->OnWorldUpdate(diff);
}
// Stats logger update
sMetric->Update();
TC_METRIC_VALUE("update_time_diff", diff);
{
TC_METRIC_TIMER("world_update_time", TC_METRIC_TAG("type", "Update metrics"));
// Stats logger update
sMetric->Update();
TC_METRIC_VALUE("update_time_diff", diff);
}
}
void World::ForceGameEventUpdate()

View File

@@ -83,7 +83,6 @@ public:
static std::vector<ChatCommand> serverSetCommandTable =
{
{ "difftime", rbac::RBAC_PERM_COMMAND_SERVER_SET_DIFFTIME, true, &HandleServerSetDiffTimeCommand, "" },
{ "loglevel", rbac::RBAC_PERM_COMMAND_SERVER_SET_LOGLEVEL, true, &HandleServerSetLogLevelCommand, "" },
{ "motd", rbac::RBAC_PERM_COMMAND_SERVER_SET_MOTD, true, &HandleServerSetMotdCommand, "" },
{ "closed", rbac::RBAC_PERM_COMMAND_SERVER_SET_CLOSED, true, &HandleServerSetClosedCommand, "" },
@@ -443,26 +442,6 @@ public:
return true;
}
// set diff time record interval
static bool HandleServerSetDiffTimeCommand(ChatHandler* /*handler*/, char const* args)
{
if (!*args)
return false;
char* newTimeStr = strtok((char*)args, " ");
if (!newTimeStr)
return false;
int32 newTime = atoi(newTimeStr);
if (newTime < 0)
return false;
sWorldUpdateTime.SetRecordUpdateTimeInterval(newTime);
printf("Record diff every %i ms\n", newTime);
return true;
}
private:
static bool ParseExitCode(char const* exitCodeStr, int32& exitCode)
{

View File

@@ -3330,23 +3330,6 @@ ShowMuteInWorld = 0
ShowBanInWorld = 0
#
# RecordUpdateTimeDiffInterval
# Description: Time (in milliseconds) update time diff is written to the log file.
# Update diff can be used as a performance indicator. Diff < 300: good
# performance. Diff > 600 bad performance, may be caused by high CPU usage.
# Default: 60000 - (Enabled, 1 minute)
# 0 - (Disabled)
RecordUpdateTimeDiffInterval = 60000
#
# MinRecordUpdateTimeDiff
# Description: Only record update time diff which is greater than this value.
# Default: 100
MinRecordUpdateTimeDiff = 100
#
# PlayerStart.String
# Description: String to be displayed at first login of newly created characters.