make logging less verbose

src/ChatCommands.cc

@@ -401,7 +401,7 @@ ChatCommandDefinition cc_bank(
       auto& bank = a.c->current_bank();
       bank.assign_ids(0x99000000 + (a.c->lobby_client_id << 20));
       a.c->log.info_f("Assigned bank item IDs");
-      a.c->print_bank(stderr);
+      a.c->print_bank();
 
       send_text_message_fmt(a.c, "{} items\n{} Meseta", bank.num_items, bank.meseta);
       co_return;

src/Client.cc

@@ -1046,30 +1046,30 @@ void Client::use_character_bank(ssize_t index) {
   }
 }
 
-void Client::print_inventory(FILE* stream) const {
+void Client::print_inventory() const {
   auto s = this->require_server_state();
   auto p = this->character();
-  phosg::fwrite_fmt(stream, "[PlayerInventory] Meseta: {}\n", p->disp.stats.meseta);
+  this->log.info_f("[PlayerInventory] Meseta: {}\n", p->disp.stats.meseta);
-  phosg::fwrite_fmt(stream, "[PlayerInventory] {} items\n", p->inventory.num_items);
+  this->log.info_f("[PlayerInventory] {} items\n", p->inventory.num_items);
   for (size_t x = 0; x < p->inventory.num_items; x++) {
     const auto& item = p->inventory.items[x];
     auto hex = item.data.hex();
     auto name = s->describe_item(this->version(), item.data, false);
-    phosg::fwrite_fmt(stream, "[PlayerInventory]   {:2}: [+{:08X}] {} ({})\n", x, item.flags, hex, name);
+    this->log.info_f("[PlayerInventory]   {:2}: [+{:08X}] {} ({})\n", x, item.flags, hex, name);
   }
 }
 
-void Client::print_bank(FILE* stream) const {
+void Client::print_bank() const {
   auto s = this->require_server_state();
   auto bank = this->current_bank();
-  phosg::fwrite_fmt(stream, "[PlayerBank] Meseta: {}\n", bank.meseta);
+  this->log.info_f("[PlayerBank] Meseta: {}\n", bank.meseta);
-  phosg::fwrite_fmt(stream, "[PlayerBank] {} items\n", bank.num_items);
+  this->log.info_f("[PlayerBank] {} items\n", bank.num_items);
   for (size_t x = 0; x < bank.num_items; x++) {
     const auto& item = bank.items[x];
     const char* present_token = item.present ? "" : " (missing present flag)";
     auto hex = item.data.hex();
     auto name = s->describe_item(this->version(), item.data, false);
-    phosg::fwrite_fmt(stream, "[PlayerBank]   {:3}: {} ({}) (x{}){}\n", x, hex, name, item.amount, present_token);
+    this->log.info_f("[PlayerBank]   {:3}: {} ({}) (x{}){}\n", x, hex, name, item.amount, present_token);
   }
 }
 

src/Client.hh

@@ -345,8 +345,8 @@ public:
   void use_character_bank(ssize_t bb_character_index);
   void use_default_bank();
 
-  void print_inventory(FILE* stream) const;
+  void print_inventory() const;
-  void print_bank(FILE* stream) const;
+  void print_bank() const;
 
   void cancel_pending_promises();
 

src/Episode3/DataIndexes.cc

@@ -2746,7 +2746,7 @@ MapIndex::MapIndex(const string& directory) {
       auto map_it = this->maps.find(vm->map->map_number);
       if (map_it == this->maps.end()) {
         map_it = this->maps.emplace(vm->map->map_number, make_shared<Map>(vm)).first;
-        static_game_data_log.info_f("({}) Created Episode 3 map {:08X} {} ({}; {})",
+        static_game_data_log.debug_f("({}) Created Episode 3 map {:08X} {} ({}; {})",
             filename,
             vm->map->map_number,
             char_for_language_code(vm->language),
@@ -2754,7 +2754,7 @@ MapIndex::MapIndex(const string& directory) {
             name);
       } else {
         map_it->second->add_version(vm);
-        static_game_data_log.info_f("({}) Added Episode 3 map version {:08X} {} ({}; {})",
+        static_game_data_log.debug_f("({}) Added Episode 3 map version {:08X} {} ({}; {})",
             filename,
             vm->map->map_number,
             char_for_language_code(vm->language),

src/FunctionCompiler.cc

@@ -320,7 +320,7 @@ FunctionCodeIndex::FunctionCodeIndex(const string& directory) {
 
         string index_prefix = code->index ? std::format("{:02X} => ", code->index) : "";
         string patch_prefix = is_patch ? std::format("[{:08X}/{:08X}] ", code->menu_item_id, code->specific_version) : "";
-        function_compiler_log.info_f("Compiled function {}{}{} ({})",
+        function_compiler_log.debug_f("Compiled function {}{}{} ({})",
             index_prefix, patch_prefix, name, name_for_architecture(code->arch));
 
       } catch (const exception& e) {
@@ -408,10 +408,9 @@ DOLFileIndex::DOLFileIndex(const string& directory) {
 
         string compressed_size_str = phosg::format_size(file_data.size());
         string decompressed_size_str = phosg::format_size(decompressed_size);
-        function_compiler_log.info_f("Loaded compressed DOL file {} ({} -> {})",
+        function_compiler_log.debug_f("Loaded compressed DOL file {} ({} -> {})",
-            dol->name, compressed_size_str, decompressed_size_str);
-        description = std::format("$C6{}$C7\n{}\n{} (orig)",
             dol->name, compressed_size_str, decompressed_size_str);
+        description = std::format("$C6{}$C7\n{}\n{} (orig)", dol->name, compressed_size_str, decompressed_size_str);
 
       } else {
         phosg::StringWriter w;
@@ -424,7 +423,7 @@ DOLFileIndex::DOLFileIndex(const string& directory) {
         dol->data = std::move(w.str());
 
         string size_str = phosg::format_size(dol->data.size());
-        function_compiler_log.info_f("Loaded DOL file {} ({})", filename, size_str);
+        function_compiler_log.debug_f("Loaded DOL file {} ({})", filename, size_str);
         description = std::format("$C6{}$C7\n{}", dol->name, size_str);
       }
 

src/Lobby.cc

@@ -774,12 +774,12 @@ void Lobby::assign_inventory_and_bank_item_ids(shared_ptr<Client> c, bool consum
   }
 
   if (c->log.info_f("Assigned inventory item IDs{}", consume_ids ? "" : " but did not mark IDs as used")) {
-    c->print_inventory(stderr);
+    c->print_inventory();
     auto& bank = c->current_bank();
     if (p->bank.num_items) {
       bank.assign_ids(0x99000000 + (c->lobby_client_id << 20));
       c->log.info_f("Assigned bank item IDs");
-      c->print_bank(stderr);
+      c->print_bank();
     } else {
       c->log.info_f("Bank is empty");
     }

src/PatchFileIndex.cc

@@ -30,7 +30,7 @@ std::shared_ptr<const std::string> PatchFileIndex::File::load_data() {
   if (!this->loaded_data) {
     string relative_path = phosg::join(this->path_directories, "/") + "/" + this->name;
     string full_path = this->index->root_dir + "/" + relative_path;
-    patch_index_log.info_f("Loading data for {}", relative_path);
+    patch_index_log.debug_f("Loading data for {}", relative_path);
     this->loaded_data = make_shared<string>(phosg::load_file(full_path));
     this->size = this->loaded_data->size();
   }
@@ -45,7 +45,7 @@ PatchFileIndex::PatchFileIndex(const string& root_dir)
   try {
     string metadata_text = phosg::load_file(metadata_cache_filename);
     metadata_cache_json = phosg::JSON::parse(metadata_text);
-    patch_index_log.info_f("Loaded patch metadata cache from {}", metadata_cache_filename);
+    patch_index_log.debug_f("Loaded patch metadata cache from {}", metadata_cache_filename);
   } catch (const exception& e) {
     metadata_cache_json = phosg::JSON::dict();
     patch_index_log.warning_f("Cannot load patch metadata cache from {}: {}", metadata_cache_filename, e.what());
@@ -62,7 +62,7 @@ PatchFileIndex::PatchFileIndex(const string& root_dir)
 
     string relative_dirs = phosg::join(path_directories, "/");
     string full_dir_path = root_dir + '/' + relative_dirs;
-    patch_index_log.info_f("Listing directory {}", full_dir_path);
+    patch_index_log.debug_f("Listing directory {}", full_dir_path);
 
     for (const auto& dir_item : std::filesystem::directory_iterator(full_dir_path)) {
       string item = dir_item.path().filename().string();
@@ -133,10 +133,10 @@ PatchFileIndex::PatchFileIndex(const string& root_dir)
         this->files_by_patch_order.emplace_back(f);
         this->files_by_name.emplace(relative_item_path, f);
         if (compute_crc32s_message.empty()) {
-          patch_index_log.info_f("Added file {} ({} bytes; {} chunks; {:08X} from cache)",
+          patch_index_log.debug_f("Added file {} ({} bytes; {} chunks; {:08X} from cache)",
               full_item_path, f->size, f->chunk_crcs.size(), f->crc32);
         } else {
-          patch_index_log.info_f("Added file {} ({} bytes; {} chunks; {:08X} [{}])",
+          patch_index_log.debug_f("Added file {} ({} bytes; {} chunks; {:08X} [{}])",
               full_item_path, f->size, f->chunk_crcs.size(), f->crc32, compute_crc32s_message);
         }
       }
@@ -150,12 +150,12 @@ PatchFileIndex::PatchFileIndex(const string& root_dir)
   if (should_write_metadata_cache) {
     try {
       phosg::save_file(metadata_cache_filename, new_metadata_cache_json.serialize());
-      patch_index_log.info_f("Saved patch metadata cache to {}", metadata_cache_filename);
+      patch_index_log.debug_f("Saved patch metadata cache to {}", metadata_cache_filename);
     } catch (const exception& e) {
       patch_index_log.warning_f("Cannot save patch metadata cache to {}: {}", metadata_cache_filename, e.what());
     }
   } else {
-    patch_index_log.info_f("No files were modified; skipping metadata cache update");
+    patch_index_log.debug_f("No files were modified; skipping metadata cache update");
   }
 }
 

src/Quest.cc

@@ -932,7 +932,7 @@ QuestIndex::QuestIndex(
       auto q_it = this->quests_by_number.find(vq->quest_number);
       if (q_it != this->quests_by_number.end()) {
         q_it->second->add_version(vq);
-        static_game_data_log.info_f("({}) Added {} {} version of quest {} ({})",
+        static_game_data_log.debug_f("({}) Added {} {} version of quest {} ({})",
             filenames_str,
             phosg::name_for_enum(vq->version),
             char_for_language_code(vq->language),
@@ -943,7 +943,7 @@ QuestIndex::QuestIndex(
         this->quests_by_number.emplace(vq->quest_number, q);
         this->quests_by_name.emplace(vq->name, q);
         this->quests_by_category_id_and_number[q->category_id].emplace(vq->quest_number, q);
-        static_game_data_log.info_f("({}) Created {} {} quest {} ({}) ({}, {} ({}), {})",
+        static_game_data_log.debug_f("({}) Created {} {} quest {} ({}) ({}, {} ({}), {})",
             filenames_str,
             phosg::name_for_enum(vq->version),
             char_for_language_code(vq->language),

src/ReceiveSubcommands.cc

@@ -1920,7 +1920,7 @@ static asio::awaitable<void> on_player_drop_item(shared_ptr<Client> c, Subcomman
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} dropped item {:08X} ({}) at {}:({:g}, {:g})",
         cmd.header.client_id, cmd.item_id, name, cmd.floor, cmd.pos.x, cmd.pos.z);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand(c, msg);
@@ -1965,7 +1965,7 @@ static asio::awaitable<void> on_create_inventory_item_t(shared_ptr<Client> c, Su
     if (l->log.should_log(phosg::LogLevel::L_INFO)) {
       auto name = s->describe_item(c->version(), item, false);
       l->log.info_f("Player {} created inventory item {:08X} ({})", c->lobby_client_id, item.id, name);
-      c->print_inventory(stderr);
+      c->print_inventory();
     }
   }
 
@@ -2009,7 +2009,7 @@ static void on_drop_partial_stack_t(shared_ptr<Client> c, SubcommandMessage& msg
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} split stack to create floor item {:08X} ({}) at {}:({:g},{:g})",
         cmd.header.client_id, item.id, name, cmd.floor, cmd.pos.x, cmd.pos.z);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand_with_item_transcode_t(c, msg.command, msg.flag, cmd);
@@ -2064,7 +2064,7 @@ static asio::awaitable<void> on_drop_partial_stack_bb(shared_ptr<Client> c, Subc
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} split stack {:08X} (removed: {}) at {}:({:g}, {:g})",
         cmd.header.client_id, cmd.item_id, name, cmd.floor, cmd.pos.x, cmd.pos.z);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
   co_return;
 }
@@ -2097,7 +2097,7 @@ static asio::awaitable<void> on_buy_shop_item(shared_ptr<Client> c, SubcommandMe
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} bought item {:08X} ({}) from shop ({} Meseta)",
         cmd.header.client_id, item.id, name, price);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand_with_item_transcode_t(c, msg.command, msg.flag, cmd);
@@ -2251,7 +2251,7 @@ static asio::awaitable<void> on_pick_up_item_generic(
       auto s = c->require_server_state();
       auto name = s->describe_item(c->version(), fi->data, false);
       l->log.info_f("Player {} picked up {:08X} ({})", client_id, item_id, name);
-      c->print_inventory(stderr);
+      c->print_inventory();
     }
 
     for (size_t z = 0; z < 12; z++) {
@@ -2384,7 +2384,7 @@ static asio::awaitable<void> on_use_item(shared_ptr<Client> c, SubcommandMessage
   if (l->log.should_log(phosg::LogLevel::L_INFO)) {
     l->log.info_f("Player {} used item {}:{:08X} ({})",
         c->lobby_client_id, cmd.header.client_id, cmd.item_id, name);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand(c, msg);
@@ -2426,7 +2426,7 @@ static asio::awaitable<void> on_feed_mag(shared_ptr<Client> c, SubcommandMessage
     l->log.info_f("Player {} fed item {}:{:08X} ({}) to mag {}:{:08X} ({})",
         c->lobby_client_id, cmd.header.client_id, cmd.fed_item_id, fed_name,
         cmd.header.client_id, cmd.mag_item_id, mag_name);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand(c, msg);
@@ -2672,7 +2672,7 @@ static asio::awaitable<void> on_ep3_private_word_select_bb_bank_action(
           string name = s->describe_item(Version::BB_V4, item, false);
           l->log.info_f("Player {} deposited item {:08X} (x{}) ({}) in the bank",
               c->lobby_client_id, cmd.item_id, cmd.item_amount, name);
-          c->print_inventory(stderr);
+          c->print_inventory();
         }
       }
 
@@ -2702,7 +2702,7 @@ static asio::awaitable<void> on_ep3_private_word_select_bb_bank_action(
           string name = s->describe_item(Version::BB_V4, item, false);
           l->log.info_f("Player {} withdrew item {:08X} (x{}) ({}) from the bank",
               c->lobby_client_id, item.id, cmd.item_amount, name);
-          c->print_inventory(stderr);
+          c->print_inventory();
         }
       }
 
@@ -4030,7 +4030,7 @@ static asio::awaitable<void> on_item_reward_request_bb(shared_ptr<Client> c, Sub
       auto name = s->describe_item(c->version(), item, false);
       l->log.info_f("Player {} created inventory item {:08X} ({}) via quest command",
           c->lobby_client_id, item.id, name);
-      c->print_inventory(stderr);
+      c->print_inventory();
     }
 
   } catch (const out_of_range&) {
@@ -4069,7 +4069,7 @@ asio::awaitable<void> on_transfer_item_via_mail_message_bb(shared_ptr<Client> c,
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} sent inventory item {}:{:08X} ({}) x{} to player {:08X}",
         c->lobby_client_id, cmd.header.client_id, cmd.item_id, name, cmd.amount, cmd.target_guild_card_number);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   // To receive an item, the player must be online, using BB, have a character
@@ -4136,7 +4136,7 @@ static asio::awaitable<void> on_exchange_item_for_team_points_bb(shared_ptr<Clie
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} exchanged inventory item {}:{:08X} ({}) for {} team points",
         c->lobby_client_id, cmd.header.client_id, cmd.item_id, name, points);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   // The original implementation forwarded the 6xCC command to all other
@@ -4169,7 +4169,7 @@ static asio::awaitable<void> on_destroy_inventory_item(shared_ptr<Client> c, Sub
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} destroyed inventory item {}:{:08X} ({})",
         c->lobby_client_id, cmd.header.client_id, cmd.item_id, name);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
   forward_subcommand(c, msg);
 }
@@ -4327,7 +4327,7 @@ static asio::awaitable<void> on_sell_item_at_shop_bb(shared_ptr<Client> c, Subco
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} sold inventory item {:08X} ({}) for {} Meseta",
         c->lobby_client_id, cmd.item_id, name, price);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
 
   forward_subcommand(c, msg);
@@ -4370,7 +4370,7 @@ static asio::awaitable<void> on_buy_shop_item_bb(shared_ptr<Client> c, Subcomman
     auto name = s->describe_item(c->version(), item, false);
     l->log.info_f("Player {} purchased item {:08X} ({}) for {} meseta",
         c->lobby_client_id, item.id, name, price);
-    c->print_inventory(stderr);
+    c->print_inventory();
   }
   co_return;
 }

src/ReplaySession.cc

@@ -480,28 +480,27 @@ ReplaySession::ReplaySession(shared_ptr<ServerState> state, FILE* input_log, boo
     }
   }
 
-  replay_log.info_f("{} clients in log", this->clients.size());
+  replay_log.debug_f("{} clients in log", this->clients.size());
   for (const auto& it : this->clients) {
     string client_str = it.second->str();
-    replay_log.info_f("  {} => {}", it.first, client_str);
+    replay_log.debug_f("  {} => {}", it.first, client_str);
   }
 
-  replay_log.info_f("{} events in replay log", num_events);
+  replay_log.debug_f("{} events in replay log", num_events);
   for (auto ev = this->first_event; ev != nullptr; ev = ev->next_event) {
     string ev_str = ev->str();
-    replay_log.info_f("  {}", ev_str);
+    replay_log.debug_f("  {}", ev_str);
   }
 }
 
 asio::awaitable<void> ReplaySession::run() {
   try {
+    replay_log.info_f("Starting replay");
     while (this->first_event) {
       if (!this->first_event->complete) {
         auto& c = this->clients.at(this->first_event->client_id);
 
-        auto ev_str = this->first_event->str();
+        replay_log.debug_f("Event: {}", this->first_event->str());
-        replay_log.info_f("Event: {}", ev_str);
-
         switch (this->first_event->type) {
           case Event::Type::CONNECT: {
             if (c->channel->connected()) {
@@ -649,6 +648,11 @@ asio::awaitable<void> ReplaySession::run() {
     }
   } catch (const exception& e) {
     replay_log.error_f("Replay failed: {}", e.what());
+    if (this->first_event) {
+      replay_log.error_f("Next pending event: {}", this->first_event->str());
+    } else {
+      replay_log.error_f("No events are pending at failure time");
+    }
     this->run_failed = true;
   }
 

src/ServerState.cc

@@ -1478,7 +1478,7 @@ void ServerState::load_bb_private_keys() {
     }
     new_keys.emplace_back(make_shared<PSOBBEncryption::KeyFile>(
         phosg::load_object_file<PSOBBEncryption::KeyFile>("system/blueburst/keys/" + filename)));
-    config_log.info_f("Loaded Blue Burst key file: {}", filename);
+    config_log.debug_f("Loaded Blue Burst key file: {}", filename);
   }
   this->bb_private_keys = std::move(new_keys);
 }
@@ -1833,43 +1833,43 @@ void ServerState::load_word_select_table() {
   const vector<string>* bb_unitxt_collection = nullptr;
   unique_ptr<UnicodeTextSet> pc_unitxt_data;
   if (this->text_index) {
-    config_log.info_f("(Word select) Using PC_V2 unitxt_e.prs from text index");
+    config_log.debug_f("(Word select) Using PC_V2 unitxt_e.prs from text index");
     pc_unitxt_collection = &this->text_index->get(Version::PC_V2, 1, 35);
   } else {
-    config_log.info_f("(Word select) Loading PC_V2 unitxt_e.prs");
+    config_log.debug_f("(Word select) Loading PC_V2 unitxt_e.prs");
     pc_unitxt_data = make_unique<UnicodeTextSet>(phosg::load_file("system/text-sets/pc-v2/unitxt_e.prs"));
     pc_unitxt_collection = &pc_unitxt_data->get(35);
   }
-  config_log.info_f("(Word select) Loading BB_V4 unitxt_ws_e.prs");
+  config_log.debug_f("(Word select) Loading BB_V4 unitxt_ws_e.prs");
   auto bb_unitxt_data = make_unique<UnicodeTextSet>(phosg::load_file("system/text-sets/bb-v4/unitxt_ws_e.prs"));
   bb_unitxt_collection = &bb_unitxt_data->get(0);
 
-  config_log.info_f("(Word select) Loading DC_NTE data");
+  config_log.debug_f("(Word select) Loading DC_NTE data");
   WordSelectSet dc_nte_ws(phosg::load_file("system/text-sets/dc-nte/ws_data.bin"), Version::DC_NTE, nullptr, true);
-  config_log.info_f("(Word select) Loading DC_11_2000 data");
+  config_log.debug_f("(Word select) Loading DC_11_2000 data");
   WordSelectSet dc_112000_ws(phosg::load_file("system/text-sets/dc-11-2000/ws_data.bin"), Version::DC_11_2000, nullptr, false);
-  config_log.info_f("(Word select) Loading DC_V1 data");
+  config_log.debug_f("(Word select) Loading DC_V1 data");
   WordSelectSet dc_v1_ws(phosg::load_file("system/text-sets/dc-v1/ws_data.bin"), Version::DC_V1, nullptr, false);
-  config_log.info_f("(Word select) Loading DC_V2 data");
+  config_log.debug_f("(Word select) Loading DC_V2 data");
   WordSelectSet dc_v2_ws(phosg::load_file("system/text-sets/dc-v2/ws_data.bin"), Version::DC_V2, nullptr, false);
-  config_log.info_f("(Word select) Loading PC_NTE data");
+  config_log.debug_f("(Word select) Loading PC_NTE data");
   WordSelectSet pc_nte_ws(phosg::load_file("system/text-sets/pc-nte/ws_data.bin"), Version::PC_NTE, pc_unitxt_collection, false);
-  config_log.info_f("(Word select) Loading PC_V2 data");
+  config_log.debug_f("(Word select) Loading PC_V2 data");
   WordSelectSet pc_v2_ws(phosg::load_file("system/text-sets/pc-v2/ws_data.bin"), Version::PC_V2, pc_unitxt_collection, false);
-  config_log.info_f("(Word select) Loading GC_NTE data");
+  config_log.debug_f("(Word select) Loading GC_NTE data");
   WordSelectSet gc_nte_ws(phosg::load_file("system/text-sets/gc-nte/ws_data.bin"), Version::GC_NTE, nullptr, false);
-  config_log.info_f("(Word select) Loading GC_V3 data");
+  config_log.debug_f("(Word select) Loading GC_V3 data");
   WordSelectSet gc_v3_ws(phosg::load_file("system/text-sets/gc-v3/ws_data.bin"), Version::GC_V3, nullptr, false);
-  config_log.info_f("(Word select) Loading GC_EP3_NTE data");
+  config_log.debug_f("(Word select) Loading GC_EP3_NTE data");
   WordSelectSet gc_ep3_nte_ws(phosg::load_file("system/text-sets/gc-ep3-nte/ws_data.bin"), Version::GC_EP3_NTE, nullptr, false);
-  config_log.info_f("(Word select) Loading GC_EP3 data");
+  config_log.debug_f("(Word select) Loading GC_EP3 data");
   WordSelectSet gc_ep3_ws(phosg::load_file("system/text-sets/gc-ep3/ws_data.bin"), Version::GC_EP3, nullptr, false);
-  config_log.info_f("(Word select) Loading XB_V3 data");
+  config_log.debug_f("(Word select) Loading XB_V3 data");
   WordSelectSet xb_v3_ws(phosg::load_file("system/text-sets/xb-v3/ws_data.bin"), Version::XB_V3, nullptr, false);
-  config_log.info_f("(Word select) Loading BB_V4 data");
+  config_log.debug_f("(Word select) Loading BB_V4 data");
   WordSelectSet bb_v4_ws(phosg::load_file("system/text-sets/bb-v4/ws_data.bin"), Version::BB_V4, bb_unitxt_collection, false);
 
-  config_log.info_f("(Word select) Generating table");
+  config_log.debug_f("(Word select) Generating table");
   this->word_select_table = make_shared<WordSelectTable>(
       dc_nte_ws, dc_112000_ws, dc_v1_ws, dc_v2_ws,
       pc_nte_ws, pc_v2_ws, gc_nte_ws, gc_v3_ws,
@@ -1908,9 +1908,10 @@ shared_ptr<ItemNameIndex> ServerState::create_item_name_index_for_version(
 }
 
 void ServerState::load_item_name_indexes() {
+  config_log.info_f("Generating item name indexes");
   for (size_t v_s = NUM_PATCH_VERSIONS; v_s < NUM_VERSIONS; v_s++) {
     Version v = static_cast<Version>(v_s);
-    config_log.info_f("Generating item name index for {}", phosg::name_for_enum(v));
+    config_log.debug_f("Generating item name index for {}", phosg::name_for_enum(v));
     this->item_name_indexes[v_s] = this->create_item_name_index_for_version(
         this->item_parameter_table(v), this->item_stack_limits(v), this->text_index);
   }
@@ -2020,10 +2021,11 @@ void ServerState::load_drop_tables() {
 
 void ServerState::load_item_definitions() {
   array<shared_ptr<const ItemParameterTable>, NUM_VERSIONS> new_item_parameter_tables;
+  config_log.info_f("Loading item definition tables");
   for (size_t v_s = NUM_PATCH_VERSIONS; v_s < NUM_VERSIONS; v_s++) {
     Version v = static_cast<Version>(v_s);
     string path = std::format("system/item-tables/ItemPMT-{}.prs", file_path_token_for_version(v));
-    config_log.info_f("Loading item definition table {}", path);
+    config_log.debug_f("Loading item definition table {}", path);
     auto data = make_shared<string>(prs_decompress(phosg::load_file(path)));
     new_item_parameter_tables[v_s] = make_shared<ItemParameterTable>(data, v);
   }

src/TextIndex.cc

@@ -479,10 +479,10 @@ TextIndex::TextIndex(
           string file_path = directory + "/" + subdirectory + "/" + it.first;
           string json_path = file_path + ".json";
           if (std::filesystem::is_regular_file(json_path)) {
-            this->log.info_f("Loading {} {} JSON text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), json_path);
+            this->log.debug_f("Loading {} {} JSON text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), json_path);
             this->add_set(version, it.second, make_shared<BinaryTextSet>(phosg::JSON::parse(phosg::load_file(json_path))));
           } else if (std::filesystem::is_regular_file(file_path)) {
-            this->log.info_f("Loading {} {} binary text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), file_path);
+            this->log.debug_f("Loading {} {} binary text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), file_path);
             this->add_set(version, it.second, make_set(phosg::load_file(file_path), it.second == 0));
           }
         }
@@ -491,16 +491,16 @@ TextIndex::TextIndex(
           string file_path = directory + "/" + subdirectory + "/" + it.first;
           string json_path = file_path + ".json";
           if (std::filesystem::is_regular_file(json_path)) {
-            this->log.info_f("Loading {} {} JSON text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), json_path);
+            this->log.debug_f("Loading {} {} JSON text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), json_path);
             this->add_set(version, it.second, make_shared<UnicodeTextSet>(phosg::JSON::parse(phosg::load_file(json_path))));
           } else {
             auto patch_file = get_patch_file ? get_patch_file(version, it.first) : nullptr;
             if (patch_file) {
-              this->log.info_f("Loading {} {} Unicode text set from {} in patch tree", phosg::name_for_enum(version), char_for_language_code(it.second), it.first);
+              this->log.debug_f("Loading {} {} Unicode text set from {} in patch tree", phosg::name_for_enum(version), char_for_language_code(it.second), it.first);
               this->add_set(version, it.second, make_set(*patch_file, it.second == 0));
             } else {
               if (std::filesystem::is_regular_file(file_path)) {
-                this->log.info_f("Loading {} {} Unicode text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), file_path);
+                this->log.debug_f("Loading {} {} Unicode text set from {}", phosg::name_for_enum(version), char_for_language_code(it.second), file_path);
                 this->add_set(version, it.second, make_set(phosg::load_file(file_path), it.second == 0));
               }
             }

tests/config.json

@@ -169,19 +169,19 @@
   "MenuEvent": "xmas",
 
   "LogLevels": {
-    "AXMessages": "INFO",
+    "ChannelExceptions": "WARNING",
-    "ChannelExceptions": "INFO",
+    "Clients": "WARNING",
-    "Clients": "INFO",
+    "CommandData": "ERROR",
-    "CommandData": "INFO",
+    "Config": "WARNING",
-    "Config": "INFO",
+    "DNSServer": "WARNING",
-    "DNSServer": "INFO",
+    "FunctionCompiler": "WARNING",
-    "FunctionCompiler": "INFO",
+    "IPStackSimulator": "WARNING",
-    "IPStackSimulator": "INFO",
+    "Lobbies": "WARNING",
-    "Lobbies": "INFO",
+    "Replay": "INFO",
-    "PlayerData": "INFO",
+    "GameServer": "WARNING",
-    "ProxyServer": "INFO",
+    "PlayerData": "WARNING",
-    "GameServer": "INFO",
+    "ProxyServer": "WARNING",
-    "StaticGameData": "INFO",
+    "StaticGameData": "WARNING",
   },
   "HideDownloadCommands": true,