#include #include #include "client/voice/VoiceClient.h" #include #include "InstanceHandler.h" #include "VirtualServer.h" #include "./manager/ConversationManager.h" #include "./music/MusicBotManager.h" using namespace std; using namespace std::chrono; using namespace ts::server; using namespace ts::protocol; using namespace ts::buffer; inline void banClientFlood(VirtualServer* server, const shared_ptr& cl, time_point until){ auto time = until.time_since_epoch().count() == 0 ? 0L : chrono::ceil(until - system_clock::now()).count(); std::string reason = "You're flooding too much"; serverInstance->banManager()->registerBan(server->getServerId(), cl->getClientDatabaseId(), reason, cl->getUid(), cl->getLoggingPeerIp(), "", "", until); for(const auto &client : server->findClientsByUid(cl->getUid())) { server->notify_client_ban(client, server->getServerRoot(), reason, time); client->close_connection(system_clock::now() + seconds(1)); } } #define BEGIN_TIMINGS() timing_begin = system_clock::now() #define END_TIMINGS(variable) \ timing_end = system_clock::now(); \ variable = duration_cast(timing_end - timing_begin); void VirtualServer::executeServerTick() { threads::MutexTryLock l(this->stateLock); //Should not attempt to shutdown or start the server while ticking if(!l) { if(this->running()) logError(this->getServerId(), "Failed to lock tick mutex!"); return; } if(!this->running()) return; try { if(lastTick.time_since_epoch().count() != 0) { auto delay = system_clock::now() - lastTick; auto delay_ms = duration_cast(delay).count(); if(delay_ms > 510) { if(delay_ms < 750) { logWarning(this->getServerId(), "Found varianzes within the server tick! (Supposed: 500ms Hold: {}ms)", delay_ms); } else { logError(this->getServerId(), "Found varianzes within the server tick! This long delay could be an issue. (Supposed: 500ms Hold: {}ms)", delay_ms); } } } lastTick = system_clock::now(); system_clock::time_point timing_begin, timing_end; milliseconds timing_update_states, timing_client_tick, timing_channel, timing_statistic, timing_groups, timing_ccache, music_manager; auto client_list = this->getClients(); { BEGIN_TIMINGS(); size_t clientOnline = 0; size_t queryOnline = 0; for(const auto& conn : client_list){ switch (conn->getType()){ case ClientType::CLIENT_TEAMSPEAK: case ClientType::CLIENT_TEASPEAK: case ClientType::CLIENT_WEB: clientOnline++; break; case ClientType::CLIENT_QUERY: case ClientType::CLIENT_MUSIC: queryOnline++; break; default: break; } } properties()[property::VIRTUALSERVER_UPTIME] = std::chrono::duration_cast(std::chrono::system_clock::now() - this->startTimestamp).count(); properties()[property::VIRTUALSERVER_CLIENTS_ONLINE] = clientOnline + queryOnline; properties()[property::VIRTUALSERVER_QUERYCLIENTS_ONLINE] = queryOnline; if(clientOnline + queryOnline == 0) //We don't need to tick, when server is empty! return; properties()[property::VIRTUALSERVER_CHANNELS_ONLINE] = this->channelTree->channel_count(); properties()[property::VIRTUALSERVER_TOTAL_PING] = this->generate_network_report().average_ping; END_TIMINGS(timing_update_states); } { BEGIN_TIMINGS(); auto flood_decrease = this->properties()[property::VIRTUALSERVER_ANTIFLOOD_POINTS_TICK_REDUCE].as(); auto flood_block = this->properties()[property::VIRTUALSERVER_ANTIFLOOD_POINTS_NEEDED_IP_BLOCK].as(); bool flag_update_spoken = this->spoken_time_timestamp + seconds(30) < system_clock::now(); system_clock::time_point tick_client_begin, tick_client_end = system_clock::now(); for(const auto& cl : client_list) { tick_client_begin = tick_client_end; if(cl->server != this) { logError(this->getServerId(), "Got registered client, but client does not think hes bound to this server!"); { lock_guard lock(this->clients.lock); for(auto& client : this->clients.clients) { if(client != cl) continue; client.reset(); this->clients.count--; break; } } continue; //Fully ha? } if(cl->floodPoints > flood_block){ if(!cl->ignoresFlood()) { banClientFlood(this, cl, system_clock::now() + minutes(10)); continue; } } if(cl->floodPoints > flood_decrease) cl->floodPoints -= flood_decrease; else cl->floodPoints = 0; cl->tick(tick_client_end); auto voice = dynamic_pointer_cast(cl); if(flag_update_spoken && voice) this->spoken_time += voice->takeSpokenTime(); tick_client_end = system_clock::now(); auto passed_time = tick_client_end - tick_client_begin; if(passed_time > microseconds(2500)) { if(passed_time > milliseconds(10)) { logError(this->serverId, "Ticking of client {:1} ({:2}) needs more that 2500 microseconds! ({:3} microseconds)", cl->getLoggingPeerIp() + ":" + to_string(cl->getPeerPort()), cl->getDisplayName(), duration_cast(tick_client_end - tick_client_begin).count() ); } else { logWarning(this->serverId, "Ticking of client {:1} ({:2}) needs more that 2500 microseconds! ({:3} microseconds)", cl->getLoggingPeerIp() + ":" + to_string(cl->getPeerPort()), cl->getDisplayName(), duration_cast(tick_client_end - tick_client_begin).count() ); } } if(cl->clientPermissions->require_db_updates()) { auto begin = system_clock::now(); serverInstance->databaseHelper()->saveClientPermissions(this->ref(), cl->getClientDatabaseId(), cl->clientPermissions); auto end = system_clock::now(); debugMessage(this->serverId, "Saved client permissions for client {} ({}) in {}ms", cl->getClientDatabaseId(), cl->getDisplayName(), duration_cast(end - begin).count()); } } if(flag_update_spoken) this->spoken_time_timestamp = system_clock::now(); END_TIMINGS(timing_client_tick); } { BEGIN_TIMINGS(); unique_lock channel_lock(this->channel_tree_lock); auto channels = this->channelTree->channels(); channel_lock.unlock(); for(const auto& channel : this->channelTree->channels()){ if(channel->channelType() == ChannelType::temporary) { auto server_channel = dynamic_pointer_cast(channel); assert(server_channel); if(server_channel->client_count() > 0 || !this->getClientsByChannelRoot(channel, true).empty()) continue; seconds deleteTimeout(0); if(channel->properties().hasProperty(property::CHANNEL_DELETE_DELAY)) deleteTimeout = seconds(channel->properties()[property::CHANNEL_DELETE_DELAY].as()); auto last_left = time_point() + milliseconds(channel->properties()[property::CHANNEL_LAST_LEFT].as()); auto channel_created = channel->createdTimestamp(); if(system_clock::now() - last_left < deleteTimeout) continue; //One second stay if(system_clock::now() - channel_created < deleteTimeout + seconds(1)) continue; //One second stay this->delete_channel(server_channel, this->serverRoot, "temporary auto delete", channel_lock, true); if(channel_lock.owns_lock()) channel_lock.unlock(); } { auto permission_manager = channel->permissions(); if(permission_manager->require_db_updates()) { auto begin = system_clock::now(); serverInstance->databaseHelper()->saveChannelPermissions(this->ref(), channel->channelId(), permission_manager); auto end = system_clock::now(); debugMessage(this->serverId, "Saved channel permissions for channel {} ({}) in {}ms", channel->channelId(), channel->name(), duration_cast(end - begin).count()); } } } END_TIMINGS(timing_channel); } { BEGIN_TIMINGS(); this->server_statistics_->tick(); { lock_guard lock(this->join_attempts_lock); if(system_clock::now() > this->join_last_decrease + seconds(5)) { for(auto& elm : this->join_attempts) if(elm.second > 0) elm.second--; auto copy = this->join_attempts; for(const auto& elm : copy) if(elm.second == 0){ auto found = find(this->join_attempts.begin(), this->join_attempts.end(), elm); if(found != this->join_attempts.end()) this->join_attempts.erase(found); } this->join_last_decrease = system_clock::now(); } } END_TIMINGS(timing_statistic); } { BEGIN_TIMINGS(); auto groups = this->getGroupManager()->availableGroups(false); for(auto& group : groups) { auto permissions = group->permissions(); if(permissions->require_db_updates()) { auto begin = system_clock::now(); serverInstance->databaseHelper()->saveGroupPermissions(this->ref(), group->groupId(), permissions); auto end = system_clock::now(); debugMessage(this->serverId, "Saved group permissions for group {} ({}) in {}ms", group->groupId(), group->name(), duration_cast(end - begin).count()); } } END_TIMINGS(timing_groups); } { BEGIN_TIMINGS(); if(this->conversation_cache_cleanup_timestamp + minutes(15) < system_clock::now()) { debugMessage(this->serverId, "Cleaning up conversation cache."); this->conversation_manager_->cleanup_cache(); conversation_cache_cleanup_timestamp = system_clock::now(); } END_TIMINGS(timing_ccache); } { BEGIN_TIMINGS(); this->music_manager_->execute_tick(); END_TIMINGS(music_manager); } if(system_clock::now() - lastTick > milliseconds(100)) { //milliseconds timing_update_states, timing_client_tick, timing_channel, timing_statistic; logError(this->serverId, "Server tick tooks to long ({}ms => Status updates: {}ms Client tick: {}ms, Channel tick: {}ms, Statistic tick: {}ms, Groups: {}ms, Conversation cache: {}ms)", duration_cast(system_clock::now() - lastTick).count(), timing_update_states.count(), timing_client_tick.count(), timing_channel.count(), timing_statistic.count(), timing_groups.count(), timing_ccache.count() ); } } catch (std::exception& ex) { logCritical(this->serverId, "Failed to tick server! Got exception message: {}", ex.what()); } }