Merge pull request #12195 from LillyJadeKatrin/retroachievements-logging

Added log statements across AchievementManager.
This commit is contained in:
Admiral H. Curtiss 2023-09-24 17:13:36 +02:00 committed by GitHub
commit 15f42eb5d8
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23

View File

@ -10,6 +10,7 @@
#include <rcheevos/include/rc_hash.h> #include <rcheevos/include/rc_hash.h>
#include "Common/HttpRequest.h" #include "Common/HttpRequest.h"
#include "Common/Logging/Log.h"
#include "Common/WorkQueueThread.h" #include "Common/WorkQueueThread.h"
#include "Core/Config/AchievementSettings.h" #include "Core/Config/AchievementSettings.h"
#include "Core/Core.h" #include "Core/Core.h"
@ -35,6 +36,7 @@ void AchievementManager::Init()
m_is_runtime_initialized = true; m_is_runtime_initialized = true;
m_queue.Reset("AchievementManagerQueue", [](const std::function<void()>& func) { func(); }); m_queue.Reset("AchievementManagerQueue", [](const std::function<void()>& func) { func(); });
LoginAsync("", [](ResponseType r_type) {}); LoginAsync("", [](ResponseType r_type) {});
INFO_LOG_FMT(ACHIEVEMENTS, "Achievement Manager Initialized");
} }
} }
@ -47,7 +49,11 @@ void AchievementManager::SetUpdateCallback(UpdateCallback callback)
AchievementManager::ResponseType AchievementManager::Login(const std::string& password) AchievementManager::ResponseType AchievementManager::Login(const std::string& password)
{ {
if (!m_is_runtime_initialized) if (!m_is_runtime_initialized)
{
ERROR_LOG_FMT(ACHIEVEMENTS, "Attempted login (sync) to RetroAchievements server without "
"Achievement Manager initialized.");
return AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED; return AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED;
}
AchievementManager::ResponseType r_type = AchievementManager::ResponseType::UNKNOWN_FAILURE; AchievementManager::ResponseType r_type = AchievementManager::ResponseType::UNKNOWN_FAILURE;
{ {
std::lock_guard lg{m_lock}; std::lock_guard lg{m_lock};
@ -62,6 +68,8 @@ void AchievementManager::LoginAsync(const std::string& password, const ResponseC
{ {
if (!m_is_runtime_initialized) if (!m_is_runtime_initialized)
{ {
ERROR_LOG_FMT(ACHIEVEMENTS, "Attempted login (async) to RetroAchievements server without "
"Achievement Manager initialized.");
callback(AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED); callback(AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED);
return; return;
} }
@ -85,6 +93,8 @@ void AchievementManager::LoadGameByFilenameAsync(const std::string& iso_path,
{ {
if (!m_is_runtime_initialized) if (!m_is_runtime_initialized)
{ {
ERROR_LOG_FMT(ACHIEVEMENTS,
"Attempted to load game achievements without Achievement Manager initialized.");
callback(AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED); callback(AchievementManager::ResponseType::MANAGER_NOT_INITIALIZED);
return; return;
} }
@ -140,12 +150,16 @@ void AchievementManager::LoadGameByFilenameAsync(const std::string& iso_path,
.close = [](void* file_handle) { delete reinterpret_cast<FilereaderState*>(file_handle); }}; .close = [](void* file_handle) { delete reinterpret_cast<FilereaderState*>(file_handle); }};
rc_hash_init_custom_filereader(&volume_reader); rc_hash_init_custom_filereader(&volume_reader);
if (!rc_hash_generate_from_file(m_game_hash.data(), RC_CONSOLE_GAMECUBE, iso_path.c_str())) if (!rc_hash_generate_from_file(m_game_hash.data(), RC_CONSOLE_GAMECUBE, iso_path.c_str()))
{
ERROR_LOG_FMT(ACHIEVEMENTS, "Unable to generate achievement hash from game file.");
return; return;
}
m_queue.EmplaceItem([this, callback] { m_queue.EmplaceItem([this, callback] {
const auto resolve_hash_response = ResolveHash(this->m_game_hash); const auto resolve_hash_response = ResolveHash(this->m_game_hash);
if (resolve_hash_response != ResponseType::SUCCESS || m_game_id == 0) if (resolve_hash_response != ResponseType::SUCCESS || m_game_id == 0)
{ {
callback(resolve_hash_response); callback(resolve_hash_response);
INFO_LOG_FMT(ACHIEVEMENTS, "No RetroAchievements data found for this game.");
OSD::AddMessage("No RetroAchievements data found for this game.", OSD::Duration::VERY_LONG, OSD::AddMessage("No RetroAchievements data found for this game.", OSD::Duration::VERY_LONG,
OSD::Color::RED); OSD::Color::RED);
return; return;
@ -155,6 +169,7 @@ void AchievementManager::LoadGameByFilenameAsync(const std::string& iso_path,
if (start_session_response != ResponseType::SUCCESS) if (start_session_response != ResponseType::SUCCESS)
{ {
callback(start_session_response); callback(start_session_response);
WARN_LOG_FMT(ACHIEVEMENTS, "Failed to connect to RetroAchievements server.");
OSD::AddMessage("Failed to connect to RetroAchievements server.", OSD::Duration::VERY_LONG, OSD::AddMessage("Failed to connect to RetroAchievements server.", OSD::Duration::VERY_LONG,
OSD::Color::RED); OSD::Color::RED);
return; return;
@ -163,10 +178,12 @@ void AchievementManager::LoadGameByFilenameAsync(const std::string& iso_path,
const auto fetch_game_data_response = FetchGameData(); const auto fetch_game_data_response = FetchGameData();
if (fetch_game_data_response != ResponseType::SUCCESS) if (fetch_game_data_response != ResponseType::SUCCESS)
{ {
ERROR_LOG_FMT(ACHIEVEMENTS, "Unable to retrieve data from RetroAchievements server.");
OSD::AddMessage("Unable to retrieve data from RetroAchievements server.", OSD::AddMessage("Unable to retrieve data from RetroAchievements server.",
OSD::Duration::VERY_LONG, OSD::Color::RED); OSD::Duration::VERY_LONG, OSD::Color::RED);
return; return;
} }
INFO_LOG_FMT(ACHIEVEMENTS, "Loading achievements for {}.", m_game_data.title);
// Claim the lock, then queue the fetch unlock data calls, then initialize the unlock map in // Claim the lock, then queue the fetch unlock data calls, then initialize the unlock map in
// ActivateDeactiveAchievements. This allows the calls to process while initializing the // ActivateDeactiveAchievements. This allows the calls to process while initializing the
@ -199,6 +216,7 @@ void AchievementManager::LoadGameByFilenameAsync(const std::string& iso_path,
ActivateDeactivateRichPresence(); ActivateDeactivateRichPresence();
// Reset this to zero so that RP immediately triggers on the first frame // Reset this to zero so that RP immediately triggers on the first frame
m_last_ping_time = 0; m_last_ping_time = 0;
INFO_LOG_FMT(ACHIEVEMENTS, "RetroAchievements successfully loaded for {}.", m_game_data.title);
if (m_update_callback) if (m_update_callback)
m_update_callback(); m_update_callback();
@ -217,6 +235,8 @@ void AchievementManager::LoadUnlockData(const ResponseCallback& callback)
const auto hardcore_unlock_response = FetchUnlockData(true); const auto hardcore_unlock_response = FetchUnlockData(true);
if (hardcore_unlock_response != ResponseType::SUCCESS) if (hardcore_unlock_response != ResponseType::SUCCESS)
{ {
ERROR_LOG_FMT(ACHIEVEMENTS,
"Failed to fetch hardcore unlock data; skipping softcore unlock.");
callback(hardcore_unlock_response); callback(hardcore_unlock_response);
return; return;
} }
@ -241,6 +261,7 @@ void AchievementManager::ActivateDeactivateAchievements()
{m_game_data.achievements[ix].id, UnlockStatus{.game_data_index = ix, .points = points}}); {m_game_data.achievements[ix].id, UnlockStatus{.game_data_index = ix, .points = points}});
ActivateDeactivateAchievement(iter.first->first, enabled, unofficial, encore); ActivateDeactivateAchievement(iter.first->first, enabled, unofficial, encore);
} }
INFO_LOG_FMT(ACHIEVEMENTS, "Achievements (de)activated.");
} }
void AchievementManager::ActivateDeactivateLeaderboards() void AchievementManager::ActivateDeactivateLeaderboards()
@ -258,6 +279,7 @@ void AchievementManager::ActivateDeactivateLeaderboards()
rc_runtime_deactivate_lboard(&m_runtime, m_game_data.leaderboards[ix].id); rc_runtime_deactivate_lboard(&m_runtime, m_game_data.leaderboards[ix].id);
} }
} }
INFO_LOG_FMT(ACHIEVEMENTS, "Leaderboards (de)activated.");
} }
void AchievementManager::ActivateDeactivateRichPresence() void AchievementManager::ActivateDeactivateRichPresence()
@ -268,6 +290,7 @@ void AchievementManager::ActivateDeactivateRichPresence()
m_game_data.rich_presence_script : m_game_data.rich_presence_script :
"", "",
nullptr, 0); nullptr, 0);
INFO_LOG_FMT(ACHIEVEMENTS, "Rich presence (de)activated.");
} }
void AchievementManager::DoFrame() void AchievementManager::DoFrame()
@ -435,6 +458,7 @@ void AchievementManager::CloseGame()
} }
if (m_update_callback) if (m_update_callback)
m_update_callback(); m_update_callback();
INFO_LOG_FMT(ACHIEVEMENTS, "Game closed.");
} }
void AchievementManager::Logout() void AchievementManager::Logout()
@ -443,6 +467,7 @@ void AchievementManager::Logout()
Config::SetBaseOrCurrent(Config::RA_API_TOKEN, ""); Config::SetBaseOrCurrent(Config::RA_API_TOKEN, "");
if (m_update_callback) if (m_update_callback)
m_update_callback(); m_update_callback();
INFO_LOG_FMT(ACHIEVEMENTS, "Logged out from server.");
} }
void AchievementManager::Shutdown() void AchievementManager::Shutdown()
@ -452,6 +477,7 @@ void AchievementManager::Shutdown()
m_queue.Shutdown(); m_queue.Shutdown();
// DON'T log out - keep those credentials for next run. // DON'T log out - keep those credentials for next run.
rc_runtime_destroy(&m_runtime); rc_runtime_destroy(&m_runtime);
INFO_LOG_FMT(ACHIEVEMENTS, "Achievement Manager shut down.");
} }
AchievementManager::ResponseType AchievementManager::VerifyCredentials(const std::string& password) AchievementManager::ResponseType AchievementManager::VerifyCredentials(const std::string& password)
@ -465,10 +491,15 @@ AchievementManager::ResponseType AchievementManager::VerifyCredentials(const std
login_request, &login_data, rc_api_init_login_request, rc_api_process_login_response); login_request, &login_data, rc_api_init_login_request, rc_api_process_login_response);
if (r_type == ResponseType::SUCCESS) if (r_type == ResponseType::SUCCESS)
{ {
INFO_LOG_FMT(ACHIEVEMENTS, "Successfully logged in to RetroAchievements server.");
Config::SetBaseOrCurrent(Config::RA_API_TOKEN, login_data.api_token); Config::SetBaseOrCurrent(Config::RA_API_TOKEN, login_data.api_token);
m_display_name = login_data.display_name; m_display_name = login_data.display_name;
m_player_score = login_data.score; m_player_score = login_data.score;
} }
else
{
WARN_LOG_FMT(ACHIEVEMENTS, "Failed to login to RetroAchievements server.");
}
rc_api_destroy_login_response(&login_data); rc_api_destroy_login_response(&login_data);
return r_type; return r_type;
} }
@ -485,7 +516,14 @@ AchievementManager::ResolveHash(std::array<char, HASH_LENGTH> game_hash)
resolve_hash_request, &hash_data, rc_api_init_resolve_hash_request, resolve_hash_request, &hash_data, rc_api_init_resolve_hash_request,
rc_api_process_resolve_hash_response); rc_api_process_resolve_hash_response);
if (r_type == ResponseType::SUCCESS) if (r_type == ResponseType::SUCCESS)
{
m_game_id = hash_data.game_id; m_game_id = hash_data.game_id;
INFO_LOG_FMT(ACHIEVEMENTS, "Hashed game ID {} for RetroAchievements.", m_game_id);
}
else
{
INFO_LOG_FMT(ACHIEVEMENTS, "Hash {} not recognized by RetroAchievements.", game_hash.data());
}
rc_api_destroy_resolve_hash_response(&hash_data); rc_api_destroy_resolve_hash_response(&hash_data);
return r_type; return r_type;
} }
@ -553,7 +591,10 @@ void AchievementManager::ActivateDeactivateAchievement(AchievementId id, bool en
{ {
auto it = m_unlock_map.find(id); auto it = m_unlock_map.find(id);
if (it == m_unlock_map.end()) if (it == m_unlock_map.end())
{
ERROR_LOG_FMT(ACHIEVEMENTS, "Attempted to unlock unknown achievement id {}.", id);
return; return;
}
const UnlockStatus& status = it->second; const UnlockStatus& status = it->second;
u32 index = status.game_data_index; u32 index = status.game_data_index;
bool active = (rc_runtime_get_achievement(&m_runtime, id) != nullptr); bool active = (rc_runtime_get_achievement(&m_runtime, id) != nullptr);
@ -622,6 +663,14 @@ AchievementManager::ResponseType AchievementManager::AwardAchievement(Achievemen
award_request, &award_response, rc_api_init_award_achievement_request, award_request, &award_response, rc_api_init_award_achievement_request,
rc_api_process_award_achievement_response); rc_api_process_award_achievement_response);
rc_api_destroy_award_achievement_response(&award_response); rc_api_destroy_award_achievement_response(&award_response);
if (r_type == ResponseType::SUCCESS)
{
INFO_LOG_FMT(ACHIEVEMENTS, "Awarded achievement ID {}.", achievement_id);
}
else
{
WARN_LOG_FMT(ACHIEVEMENTS, "Failed to award achievement ID {}.", achievement_id);
}
return r_type; return r_type;
} }
@ -641,6 +690,14 @@ AchievementManager::ResponseType AchievementManager::SubmitLeaderboard(Achieveme
submit_request, &submit_response, rc_api_init_submit_lboard_entry_request, submit_request, &submit_response, rc_api_init_submit_lboard_entry_request,
rc_api_process_submit_lboard_entry_response); rc_api_process_submit_lboard_entry_response);
rc_api_destroy_submit_lboard_entry_response(&submit_response); rc_api_destroy_submit_lboard_entry_response(&submit_response);
if (r_type == ResponseType::SUCCESS)
{
INFO_LOG_FMT(ACHIEVEMENTS, "Submitted leaderboard ID {}.", leaderboard_id);
}
else
{
WARN_LOG_FMT(ACHIEVEMENTS, "Failed to submit leaderboard ID {}.", leaderboard_id);
}
return r_type; return r_type;
} }
@ -664,7 +721,11 @@ void AchievementManager::HandleAchievementTriggeredEvent(const rc_runtime_event_
{ {
auto it = m_unlock_map.find(runtime_event->id); auto it = m_unlock_map.find(runtime_event->id);
if (it == m_unlock_map.end()) if (it == m_unlock_map.end())
{
ERROR_LOG_FMT(ACHIEVEMENTS, "Invalid achievement triggered event with id {}.",
runtime_event->id);
return; return;
}
it->second.session_unlock_count++; it->second.session_unlock_count++;
m_queue.EmplaceItem([this, runtime_event] { AwardAchievement(runtime_event->id); }); m_queue.EmplaceItem([this, runtime_event] { AwardAchievement(runtime_event->id); });
AchievementId game_data_index = it->second.game_data_index; AchievementId game_data_index = it->second.game_data_index;
@ -698,9 +759,10 @@ void AchievementManager::HandleLeaderboardStartedEvent(const rc_runtime_event_t*
{ {
OSD::AddMessage(fmt::format("Attempting leaderboard: {}", m_game_data.leaderboards[ix].title), OSD::AddMessage(fmt::format("Attempting leaderboard: {}", m_game_data.leaderboards[ix].title),
OSD::Duration::VERY_LONG, OSD::Color::GREEN); OSD::Duration::VERY_LONG, OSD::Color::GREEN);
break; return;
} }
} }
ERROR_LOG_FMT(ACHIEVEMENTS, "Invalid leaderboard started event with id {}.", runtime_event->id);
} }
void AchievementManager::HandleLeaderboardCanceledEvent(const rc_runtime_event_t* runtime_event) void AchievementManager::HandleLeaderboardCanceledEvent(const rc_runtime_event_t* runtime_event)
@ -711,9 +773,10 @@ void AchievementManager::HandleLeaderboardCanceledEvent(const rc_runtime_event_t
{ {
OSD::AddMessage(fmt::format("Failed leaderboard: {}", m_game_data.leaderboards[ix].title), OSD::AddMessage(fmt::format("Failed leaderboard: {}", m_game_data.leaderboards[ix].title),
OSD::Duration::VERY_LONG, OSD::Color::RED); OSD::Duration::VERY_LONG, OSD::Color::RED);
break; return;
} }
} }
ERROR_LOG_FMT(ACHIEVEMENTS, "Invalid leaderboard canceled event with id {}.", runtime_event->id);
} }
void AchievementManager::HandleLeaderboardTriggeredEvent(const rc_runtime_event_t* runtime_event) void AchievementManager::HandleLeaderboardTriggeredEvent(const rc_runtime_event_t* runtime_event)
@ -740,9 +803,10 @@ void AchievementManager::HandleLeaderboardTriggeredEvent(const rc_runtime_event_
m_game_data.leaderboards[ix].title), m_game_data.leaderboards[ix].title),
OSD::Duration::VERY_LONG, OSD::Color::YELLOW); OSD::Duration::VERY_LONG, OSD::Color::YELLOW);
} }
break; return;
} }
} }
ERROR_LOG_FMT(ACHIEVEMENTS, "Invalid leaderboard triggered event with id {}.", runtime_event->id);
} }
// Every RetroAchievements API call, with only a partial exception for fetch_image, follows // Every RetroAchievements API call, with only a partial exception for fetch_image, follows
@ -763,7 +827,10 @@ AchievementManager::ResponseType AchievementManager::Request(
rc_api_request_t api_request; rc_api_request_t api_request;
Common::HttpRequest http_request; Common::HttpRequest http_request;
if (init_request(&api_request, &rc_request) != RC_OK || !api_request.post_data) if (init_request(&api_request, &rc_request) != RC_OK || !api_request.post_data)
{
ERROR_LOG_FMT(ACHIEVEMENTS, "Invalid API request.");
return ResponseType::INVALID_REQUEST; return ResponseType::INVALID_REQUEST;
}
auto http_response = http_request.Post(api_request.url, api_request.post_data); auto http_response = http_request.Post(api_request.url, api_request.post_data);
rc_api_destroy_request(&api_request); rc_api_destroy_request(&api_request);
if (http_response.has_value() && http_response->size() > 0) if (http_response.has_value() && http_response->size() > 0)
@ -777,11 +844,13 @@ AchievementManager::ResponseType AchievementManager::Request(
else else
{ {
Logout(); Logout();
WARN_LOG_FMT(ACHIEVEMENTS, "Invalid RetroAchievements credentials; failed login.");
return ResponseType::INVALID_CREDENTIALS; return ResponseType::INVALID_CREDENTIALS;
} }
} }
else else
{ {
WARN_LOG_FMT(ACHIEVEMENTS, "RetroAchievements connection failed.");
return ResponseType::CONNECTION_FAILED; return ResponseType::CONNECTION_FAILED;
} }
} }