diff --git a/builtin/game/chat.lua b/builtin/game/chat.lua index 64f14cc40..80c9a6e81 100644 --- a/builtin/game/chat.lua +++ b/builtin/game/chat.lua @@ -60,6 +60,8 @@ core.register_on_chat_message(function(name, message) param = param or "" + core.log("verbose", string.format("Handling chat command %q with params %q", cmd, param)) + -- Run core.registered_on_chatcommands callbacks. if core.run_callbacks(core.registered_on_chatcommands, 5, name, cmd, param) then return true diff --git a/src/client/client.cpp b/src/client/client.cpp index cf19d7e58..1859356b9 100644 --- a/src/client/client.cpp +++ b/src/client/client.cpp @@ -869,6 +869,8 @@ bool Client::loadMedia(const std::string &data, const std::string &filename, const char *font_ext[] = {".ttf", ".woff", NULL}; name = removeStringEnd(filename, font_ext); if (!name.empty()) { + verbosestream<<"Client: Loading file as font: \"" + << filename << "\"" << std::endl; g_fontengine->setMediaFont(name, data); return true; } diff --git a/src/client/shader.cpp b/src/client/shader.cpp index 5924e935a..3ecbb4f38 100644 --- a/src/client/shader.cpp +++ b/src/client/shader.cpp @@ -451,9 +451,6 @@ u32 ShaderSource::getShaderIdDirect(const std::string &name, u32 id = m_shaderinfo_cache.size(); m_shaderinfo_cache.push_back(info); - infostream<<"getShaderIdDirect(): " - <<"Returning id="< @@ -81,14 +82,19 @@ inline std::wstring fwgettext(const char *src, Args&&... args) template inline std::string fmtgettext(const char *format, Args&&... args) { - std::string buf; - std::size_t buf_size = 256; - buf.resize(buf_size); - format = gettext(format); - int len = porting::mt_snprintf(&buf[0], buf_size, format, std::forward(args)...); - if (len <= 0) throw std::runtime_error("gettext format error: " + std::string(format)); + std::string buf; + { + size_t default_size = strlen(format); + if (default_size < 256) + default_size = 256; + buf.resize(default_size); + } + + int len = porting::mt_snprintf(&buf[0], buf.size(), format, std::forward(args)...); + if (len <= 0) + throw std::runtime_error("gettext format error: " + std::string(format)); if ((size_t)len >= buf.size()) { buf.resize(len+1); // extra null byte porting::mt_snprintf(&buf[0], buf.size(), format, std::forward(args)...); diff --git a/src/nodedef.cpp b/src/nodedef.cpp index 2fc3264bc..8ef6f8493 100644 --- a/src/nodedef.cpp +++ b/src/nodedef.cpp @@ -1299,7 +1299,7 @@ content_t NodeDefManager::set(const std::string &name, const ContentFeatures &de // Get new id id = allocateId(); if (id == CONTENT_IGNORE) { - warningstream << "NodeDefManager: Absolute " + errorstream << "NodeDefManager: Absolute " "limit reached" << std::endl; return CONTENT_IGNORE; } @@ -1307,15 +1307,14 @@ content_t NodeDefManager::set(const std::string &name, const ContentFeatures &de addNameIdMapping(id, name); } - // If there is already ContentFeatures registered for this id, clear old groups - if (id < m_content_features.size()) - eraseIdFromGroups(id); + // Clear old groups in case of re-registration + eraseIdFromGroups(id); m_content_features[id] = def; m_content_features[id].floats = itemgroup_get(def.groups, "float") != 0; m_content_lighting_flag_cache[id] = def.getLightingFlags(); - verbosestream << "NodeDefManager: registering content id \"" << id - << "\": name=\"" << def.name << "\""<= m_content_features.size()) - m_content_features.resize((u32)(i) + 1); + m_content_features.resize((size_t)(i) + 1); m_content_features[i] = f; m_content_features[i].floats = itemgroup_get(f.groups, "float") != 0; m_content_lighting_flag_cache[i] = f.getLightingFlags(); @@ -1598,13 +1596,6 @@ void NodeDefManager::resetNodeResolveState() m_pending_resolve_callbacks.clear(); } -static void removeDupes(std::vector &list) -{ - std::sort(list.begin(), list.end()); - auto new_end = std::unique(list.begin(), list.end()); - list.erase(new_end, list.end()); -} - void NodeDefManager::resolveCrossrefs() { for (ContentFeatures &f : m_content_features) { @@ -1619,7 +1610,7 @@ void NodeDefManager::resolveCrossrefs() for (const std::string &name : f.connects_to) { getIds(name, f.connects_to_ids); } - removeDupes(f.connects_to_ids); + SORT_AND_UNIQUE(f.connects_to_ids); } } diff --git a/src/pathfinder.cpp b/src/pathfinder.cpp index 9509ba88a..d2cfebb4f 100644 --- a/src/pathfinder.cpp +++ b/src/pathfinder.cpp @@ -879,10 +879,10 @@ PathCost Pathfinder::calcCost(v3s16 pos, v3s16 dir) DEBUG_OUT("Pathfinder cost below height found" << std::endl); } else { - INFO_TARGET << "Pathfinder:" + DEBUG_OUT("Pathfinder:" " distance to surface below too big: " << (testpos.Y - pos2.Y) << " max: " << m_maxdrop - << std::endl; + << std::endl); } } else { diff --git a/src/script/lua_api/l_mapgen.cpp b/src/script/lua_api/l_mapgen.cpp index 8d3df7213..49c28172b 100644 --- a/src/script/lua_api/l_mapgen.cpp +++ b/src/script/lua_api/l_mapgen.cpp @@ -428,7 +428,7 @@ size_t get_biome_list(lua_State *L, int index, if (is_single) { Biome *biome = get_or_load_biome(L, index, biomemgr); if (!biome) { - infostream << "get_biome_list: failed to get biome '" + warningstream << "get_biome_list: failed to get biome '" << (lua_isstring(L, index) ? lua_tostring(L, index) : "") << "'." << std::endl; return 1; @@ -445,7 +445,7 @@ size_t get_biome_list(lua_State *L, int index, Biome *biome = get_or_load_biome(L, -1, biomemgr); if (!biome) { fail_count++; - infostream << "get_biome_list: failed to get biome '" + warningstream << "get_biome_list: failed to get biome '" << (lua_isstring(L, -1) ? lua_tostring(L, -1) : "") << "'" << std::endl; continue; diff --git a/src/server.cpp b/src/server.cpp index 68b27513d..13e46883a 100644 --- a/src/server.cpp +++ b/src/server.cpp @@ -567,8 +567,7 @@ void Server::start() { init(); - infostream << "Starting server on " << m_bind_addr.serializeString() - << "..." << std::endl; + infostream << "Starting server thread..." << std::endl; // Stop thread if already running m_thread->stop(); @@ -967,6 +966,7 @@ void Server::AsyncRunStep(float dtime, bool initial_step) // We'll log the amount of each Profiler prof; + size_t block_count = 0; std::unordered_set node_meta_updates; while (!m_unsent_map_edit_queue.empty()) { @@ -1015,6 +1015,8 @@ void Server::AsyncRunStep(float dtime, bool initial_step) break; } + block_count += event->modified_blocks.size(); + /* Set blocks not sent to far players */ @@ -1026,11 +1028,9 @@ void Server::AsyncRunStep(float dtime, bool initial_step) delete event; } - if (event_count >= 5) { - infostream << "Server: MapEditEvents:" << std::endl; - prof.print(infostream); - } else if (event_count != 0) { - verbosestream << "Server: MapEditEvents:" << std::endl; + if (event_count != 0) { + verbosestream << "Server: MapEditEvents modified total " + << block_count << " blocks:" << std::endl; prof.print(verbosestream); } @@ -1310,9 +1310,7 @@ void Server::ProcessData(NetworkPacket *pkt) } if (m_clients.getClientState(peer_id) < CS_Active) { - if (command == TOSERVER_PLAYERPOS) return; - - errorstream << "Server: Got packet command " + warningstream << "Server: Got packet command " << static_cast(command) << " for peer id " << peer_id << " but client isn't active yet. Dropping packet." << std::endl; @@ -2166,10 +2164,6 @@ void Server::SendActiveObjectRemoveAdd(RemoteClient *client, PlayerSAO *playersa } Send(&pkt); - - verbosestream << "Server::SendActiveObjectRemoveAdd(): " - << removed_objects.size() << " removed, " << added_objects.size() - << " added, packet size is " << pkt.getSize() << std::endl; } void Server::SendActiveObjectMessages(session_t peer_id, const std::string &datas, @@ -3921,7 +3915,11 @@ std::string Server::getBuiltinLuaPath() void Server::setAsyncFatalError(const std::string &error) { + // print error right here in the thread that set it, for clearer logging + infostream << "setAsyncFatalError: " << error << std::endl; + m_async_fatal_error.set(error); + // make sure server steps stop happening immediately if (m_thread) m_thread->stop(); diff --git a/src/server/mods.cpp b/src/server/mods.cpp index bfafe701d..1aee40a1a 100644 --- a/src/server/mods.cpp +++ b/src/server/mods.cpp @@ -42,21 +42,25 @@ void ServerModManager::loadMods(ServerScripting &script) for (const ModSpec &mod : configuration.getMods()) { infostream << mod.name << " "; } - infostream << std::endl; + // Load and run "mod" scripts + auto t0 = porting::getTimeMs(); for (const ModSpec &mod : configuration.getMods()) { mod.checkAndLog(); + auto t1 = porting::getTimeMs(); std::string script_path = mod.path + DIR_DELIM + "init.lua"; - auto t = porting::getTimeMs(); script.loadMod(script_path, mod.name); infostream << "Mod \"" << mod.name << "\" loaded after " - << (porting::getTimeMs() - t) << " ms" << std::endl; + << (porting::getTimeMs() - t1) << " ms" << std::endl; } // Run a callback when mods are loaded script.on_mods_loaded(); + + infostream << "All mods loaded after " << (porting::getTimeMs() - t0) + << " ms" << std::endl; } const ModSpec *ServerModManager::getModSpec(const std::string &modname) const diff --git a/src/serverenvironment.cpp b/src/serverenvironment.cpp index 55306ee59..9014c7017 100644 --- a/src/serverenvironment.cpp +++ b/src/serverenvironment.cpp @@ -472,28 +472,25 @@ void ServerEnvironment::loadMeta() SANITY_CHECK(!m_meta_loaded); m_meta_loaded = true; + // This has nothing to do with this method but it's nice to know + infostream << "ServerEnvironment: " << m_abms.size() << " ABMs are registered" << std::endl; + std::string path = m_server->getWorldPath() + DIR_DELIM "env_meta.txt"; // If file doesn't exist, load default environment metadata if (!fs::PathExists(path)) { - infostream << "ServerEnvironment: Loading default environment metadata" - << std::endl; loadDefaultMeta(); return; } - infostream << "ServerEnvironment: Loading environment metadata" << std::endl; + infostream << "ServerEnvironment: Loading environment metadata from file" << std::endl; // Open file and deserialize - std::ifstream is(path.c_str(), std::ios_base::binary); - if (!is.good()) { - infostream << "ServerEnvironment::loadMeta(): Failed to open " - << path << std::endl; + auto is = open_ifstream(path.c_str(), true); + if (!is.good()) throw SerializationError("Couldn't load env meta"); - } Settings args("EnvArgsEnd"); - if (!args.parseConfigLines(is)) { throw SerializationError("ServerEnvironment::loadMeta(): " "EnvArgsEnd not found!"); @@ -503,32 +500,32 @@ void ServerEnvironment::loadMeta() m_game_time = args.getU64("game_time"); } catch (SettingNotFoundException &e) { // Getting this is crucial, otherwise timestamps are useless - throw SerializationError("Couldn't load env meta game_time"); + throw SerializationError("Couldn't read game_time from env meta"); } setTimeOfDay(args.exists("time_of_day") ? - // set day to early morning by default + // if it's missing for some reason, set early morning args.getU64("time_of_day") : 5250); m_last_clear_objects_time = args.exists("last_clear_objects_time") ? // If missing, do as if clearObjects was never called args.getU64("last_clear_objects_time") : 0; + m_day_count = args.exists("day_count") ? args.getU32("day_count") : 0; + std::string lbm_introduction_times; try { - u64 ver = args.getU64("lbm_introduction_times_version"); + u32 ver = args.getU32("lbm_introduction_times_version"); if (ver == 1) { lbm_introduction_times = args.get("lbm_introduction_times"); } else { - infostream << "ServerEnvironment::loadMeta(): Non-supported" + warningstream << "ServerEnvironment::loadMeta(): Unsupported" << " introduction time version " << ver << std::endl; } } catch (SettingNotFoundException &e) { // No problem, this is expected. Just continue with an empty string } m_lbm_mgr.loadIntroductionTimes(lbm_introduction_times, m_server, m_game_time); - - m_day_count = args.exists("day_count") ? args.getU32("day_count") : 0; } /** @@ -536,6 +533,8 @@ void ServerEnvironment::loadMeta() */ void ServerEnvironment::loadDefaultMeta() { + infostream << "ServerEnvironment: Using default environment metadata" + << std::endl; m_lbm_mgr.loadIntroductionTimes("", m_server, m_game_time); } @@ -1694,13 +1693,14 @@ void ServerEnvironment::deactivateFarObjects(const bool _force_delete) if (!force_delete && still_active) return false; - verbosestream << "ServerEnvironment::deactivateFarObjects(): " - << "deactivating object id=" << id << " on inactive block " - << blockpos_o << std::endl; - // If known by some client, don't immediately delete. bool pending_delete = (obj->m_known_by_count > 0 && !force_delete); + verbosestream << "ServerEnvironment::deactivateFarObjects(): " + << "deactivating object id=" << id << " on inactive block " + << blockpos_o << (pending_delete ? " (pending)" : "") + << std::endl; + /* Update the static data */ @@ -1759,17 +1759,9 @@ void ServerEnvironment::deactivateFarObjects(const bool _force_delete) // This ensures that LuaEntity on_deactivate is always called. obj->markForDeactivation(); - /* - If known by some client, set pending deactivation. - Otherwise delete it immediately. - */ - if (pending_delete && !force_delete) { - verbosestream << "ServerEnvironment::deactivateFarObjects(): " - << "object id=" << id << " is known by clients" - << "; not deleting yet" << std::endl; - + // If known by some client, don't delete yet. + if (pending_delete && !force_delete) return false; - } processActiveObjectRemove(obj);