feat: Enhance Logging and Buffer Management in ROM and Editor Components

- Added critical logging for graphics buffer management in LoadAllGraphicsData to prevent data corruption during ROM loads.
- Updated logging levels from INFO to DEBUG across various components for consistency and to reduce log verbosity.
- Refactored texture creation and palette application logic to allow editors to manage their own rendering, improving flexibility and user experience.
- Improved background buffer handling to ensure fresh bitmap creation only when necessary, optimizing performance.
- Enhanced debugging output for canvas and performance tracking, aiding in better diagnostics during development.
This commit is contained in:
scawful
2025-10-07 11:56:53 -04:00
parent 167dc86819
commit 33f64f38a5
14 changed files with 132 additions and 119 deletions

View File

@@ -7,6 +7,7 @@
#include "app/gui/canvas.h"
#include "app/gui/input.h"
#include "app/rom.h"
#include "util/log.h"
#include "app/zelda3/dungeon/object_drawer.h"
#include "app/zelda3/dungeon/object_renderer.h"
#include "app/zelda3/dungeon/room.h"
@@ -106,13 +107,8 @@ void DungeonCanvasViewer::DrawDungeonCanvas(int room_id) {
auto& bg1_bitmap = room.bg1_buffer().bitmap();
bool needs_render = !bg1_bitmap.is_active() || bg1_bitmap.width() == 0;
printf("[DrawCanvas] Room %d: needs_render=%d, bg1_active=%d, blocks=%zu, objects=%zu\n",
room_id, needs_render, bg1_bitmap.is_active(),
room.blocks().size(), room.GetTileObjects().size());
// Render immediately if needed
if (needs_render) {
printf("[DrawCanvas] Rendering room %d graphics...\n", room_id);
(void)LoadAndRenderRoomGraphics(room_id);
}
@@ -683,30 +679,20 @@ void DungeonCanvasViewer::RenderRoomBackgroundLayers(int room_id) {
auto& bg1_bitmap = room.bg1_buffer().bitmap();
auto& bg2_bitmap = room.bg2_buffer().bitmap();
printf("[RenderLayers] Room %d: BG1 active=%d, texture=%p\n",
room_id, bg1_bitmap.is_active(), (void*)bg1_bitmap.texture());
if (bg1_bitmap.is_active() && bg1_bitmap.width() > 0 && bg1_bitmap.height() > 0) {
if (!bg1_bitmap.texture()) {
printf("[RenderLayers] Creating BG1 texture...\n");
core::Renderer::Get().RenderBitmap(&bg1_bitmap);
}
printf("[RenderLayers] Drawing BG1 bitmap: %dx%d, texture=%p\n",
bg1_bitmap.width(), bg1_bitmap.height(), (void*)bg1_bitmap.texture());
// DEBUG: Check SDL texture format
Uint32 format;
int access, w, h;
if (SDL_QueryTexture(bg1_bitmap.texture(), &format, &access, &w, &h) == 0) {
printf("[RenderLayers] BG1 texture format: %s (%u), access: %d, size: %dx%d\n",
SDL_GetPixelFormatName(format), format, access, w, h);
const char* format_name_cstr = SDL_GetPixelFormatName(format);
}
canvas_.DrawBitmap(bg1_bitmap, 0, 0, 1.0f, 255);
} else {
printf("[RenderLayers] BG1 not ready: active=%d, w=%d, h=%d\n",
bg1_bitmap.is_active(), bg1_bitmap.width(), bg1_bitmap.height());
}
}
if (bg2_bitmap.is_active() && bg2_bitmap.width() > 0 && bg2_bitmap.height() > 0) {
if (!bg2_bitmap.texture()) {

View File

@@ -40,7 +40,7 @@ absl::Status DungeonRoomLoader::LoadAllRooms(std::array<zelda3::Room, 0x128>& ro
static_cast<int>(std::thread::hardware_concurrency()));
const int rooms_per_thread = (kTotalRooms + max_concurrency - 1) / max_concurrency;
LOG_INFO("Dungeon", "Loading %d dungeon rooms using %d threads (%d rooms per thread)",
LOG_DEBUG("Dungeon", "Loading %d dungeon rooms using %d threads (%d rooms per thread)",
kTotalRooms, max_concurrency, rooms_per_thread);
// Thread-safe data structures for collecting results

View File

@@ -682,7 +682,7 @@ absl::Status EditorManager::Update() {
// Ensure TestManager always has the current ROM
static Rom* last_test_rom = nullptr;
if (last_test_rom != current_rom_) {
LOG_INFO("EditorManager",
LOG_DEBUG("EditorManager",
"EditorManager::Update - ROM changed, updating TestManager: %p -> "
"%p",
(void*)last_test_rom, (void*)current_rom_);
@@ -2039,7 +2039,7 @@ absl::Status EditorManager::LoadRom() {
for (auto& session : sessions_) {
if (!session.rom.is_loaded()) {
target_session = &session;
LOG_INFO("EditorManager", "Found empty session to populate with ROM: %s",
LOG_DEBUG("EditorManager", "Found empty session to populate with ROM: %s",
file_name.c_str());
break;
}
@@ -2067,7 +2067,7 @@ absl::Status EditorManager::LoadRom() {
// Update test manager with current ROM for ROM-dependent tests (only when tests are enabled)
#ifdef YAZE_ENABLE_TESTING
LOG_INFO("EditorManager", "Setting ROM in TestManager - %p ('%s')",
LOG_DEBUG("EditorManager", "Setting ROM in TestManager - %p ('%s')",
(void*)current_rom_,
current_rom_ ? current_rom_->title().c_str() : "null");
test::TestManager::Get().SetCurrentRom(current_rom_);
@@ -2113,7 +2113,7 @@ absl::Status EditorManager::LoadAssets() {
auto end_time = std::chrono::steady_clock::now();
auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(
end_time - start_time);
LOG_INFO("EditorManager", "ROM assets loaded in %lld ms", duration.count());
LOG_DEBUG("EditorManager", "ROM assets loaded in %lld ms", duration.count());
return absl::OkStatus();
}
@@ -2273,7 +2273,7 @@ absl::Status EditorManager::OpenProject() {
// Update test manager with current ROM for ROM-dependent tests (only when tests are enabled)
#ifdef YAZE_ENABLE_TESTING
LOG_INFO("EditorManager", "Setting ROM in TestManager - %p ('%s')",
LOG_DEBUG("EditorManager", "Setting ROM in TestManager - %p ('%s')",
(void*)current_rom_,
current_rom_ ? current_rom_->title().c_str() : "null");
test::TestManager::Get().SetCurrentRom(current_rom_);
@@ -2537,7 +2537,7 @@ void EditorManager::RemoveSession(size_t index) {
sessions_[index].custom_name = "[CLOSED SESSION]";
sessions_[index].filepath = "";
LOG_INFO("EditorManager", "Marked session as closed: %s (index %zu)",
LOG_DEBUG("EditorManager", "Marked session as closed: %s (index %zu)",
session_name.c_str(), index);
toast_manager_.Show(
absl::StrFormat("Session marked as closed: %s", session_name),

View File

@@ -78,7 +78,7 @@ void OverworldEditor::Initialize() {
absl::Status OverworldEditor::Load() {
gfx::ScopedTimer timer("OverworldEditor::Load");
LOG_INFO("OverworldEditor", "Loading overworld.");
LOG_DEBUG("OverworldEditor", "Loading overworld.");
if (!rom_ || !rom_->is_loaded()) {
return absl::FailedPreconditionError("ROM not loaded");
}
@@ -100,7 +100,7 @@ absl::Status OverworldEditor::Load() {
// Force refresh of the current overworld map to show changes
RefreshOverworldMap();
LOG_INFO("OverworldEditor", "Overworld editor refreshed after Tile16 changes");
LOG_DEBUG("OverworldEditor", "Overworld editor refreshed after Tile16 changes");
return absl::OkStatus();
});
@@ -807,7 +807,7 @@ void OverworldEditor::CheckForOverworldEdits() {
auto tile_data = gfx::GetTilemapData(tile16_blockset_, tile16_id);
if (!tile_data.empty()) {
RenderUpdatedMapBitmap(tile_position, tile_data);
LOG_INFO("OverworldEditor",
LOG_DEBUG("OverworldEditor",
"CheckForOverworldEdits: Updated bitmap at position (%d,%d) "
"with tile16_id=%d",
x, y, tile16_id);
@@ -824,7 +824,7 @@ void OverworldEditor::CheckForOverworldEdits() {
// This is commented out for now, will come back to later.
// ow_map_canvas_.mutable_selected_tiles()->clear();
// ow_map_canvas_.mutable_points()->clear();
LOG_INFO("OverworldEditor",
LOG_DEBUG("OverworldEditor",
"CheckForOverworldEdits: Rectangle selection applied and cleared");
}
}
@@ -1469,7 +1469,7 @@ absl::Status OverworldEditor::Save() {
absl::Status OverworldEditor::LoadGraphics() {
gfx::ScopedTimer timer("LoadGraphics");
LOG_INFO("OverworldEditor", "Loading overworld.");
LOG_DEBUG("OverworldEditor", "Loading overworld.");
// Load the Link to the Past overworld.
{
gfx::ScopedTimer load_timer("Overworld::Load");
@@ -1477,7 +1477,7 @@ absl::Status OverworldEditor::LoadGraphics() {
}
palette_ = overworld_.current_area_palette();
LOG_INFO("OverworldEditor", "Loading overworld graphics (optimized).");
LOG_DEBUG("OverworldEditor", "Loading overworld graphics (optimized).");
// Phase 1: Create bitmaps without textures for faster loading
// This avoids blocking the main thread with GPU texture creation
@@ -1488,7 +1488,7 @@ absl::Status OverworldEditor::LoadGraphics() {
current_gfx_bmp_, palette_);
}
LOG_INFO("OverworldEditor", "Loading overworld tileset (deferred textures).");
LOG_DEBUG("OverworldEditor", "Loading overworld tileset (deferred textures).");
{
gfx::ScopedTimer tileset_timer("CreateBitmapWithoutTexture_Tileset");
Renderer::Get().CreateBitmapWithoutTexture(
@@ -1499,7 +1499,7 @@ absl::Status OverworldEditor::LoadGraphics() {
// Copy the tile16 data into individual tiles.
auto tile16_blockset_data = overworld_.tile16_blockset_data();
LOG_INFO("OverworldEditor", "Loading overworld tile16 graphics.");
LOG_DEBUG("OverworldEditor", "Loading overworld tile16 graphics.");
{
gfx::ScopedTimer tilemap_timer("CreateTilemap");
@@ -1517,7 +1517,7 @@ absl::Status OverworldEditor::LoadGraphics() {
constexpr int kSpecialWorldEssential =
zelda3::kSpecialWorldMapIdStart + kEssentialMapsPerWorld;
LOG_INFO("OverworldEditor",
LOG_DEBUG("OverworldEditor",
"Creating bitmaps for essential maps only (first %d maps per world)",
kEssentialMapsPerWorld);
@@ -2049,7 +2049,7 @@ void OverworldEditor::ForceRefreshGraphics(int map_index) {
// Clear blockset cache
current_blockset_ = 0xFF;
LOG_INFO("OverworldEditor", "ForceRefreshGraphics: Map %d marked for refresh", map_index);
LOG_DEBUG("OverworldEditor", "ForceRefreshGraphics: Map %d marked for refresh", map_index);
}
}
@@ -2097,7 +2097,7 @@ void OverworldEditor::RefreshSiblingMapGraphics(int map_index, bool include_self
// Call RefreshChildMapOnDemand() directly instead of RefreshOverworldMapOnDemand()
RefreshChildMapOnDemand(sibling);
LOG_INFO("OverworldEditor", "RefreshSiblingMapGraphics: Refreshed sibling map %d", sibling);
LOG_DEBUG("OverworldEditor", "RefreshSiblingMapGraphics: Refreshed sibling map %d", sibling);
}
}
}
@@ -2520,7 +2520,7 @@ absl::Status OverworldEditor::ApplyZSCustomOverworldASM(int target_version) {
"ROM is already version %d or higher", current_version));
}
LOG_INFO("OverworldEditor", "Applying ZSCustomOverworld ASM v%d to ROM...",
LOG_DEBUG("OverworldEditor", "Applying ZSCustomOverworld ASM v%d to ROM...",
target_version);
// Initialize Asar wrapper
@@ -2540,7 +2540,7 @@ absl::Status OverworldEditor::ApplyZSCustomOverworldASM(int target_version) {
// Use GetResourcePath to handle app bundles and various deployment scenarios
std::string asm_file_path = util::GetResourcePath(asm_file_name);
LOG_INFO("OverworldEditor", "Using ASM file: %s", asm_file_path.c_str());
LOG_DEBUG("OverworldEditor", "Using ASM file: %s", asm_file_path.c_str());
// Verify file exists
if (!std::filesystem::exists(asm_file_path)) {
@@ -2581,17 +2581,17 @@ absl::Status OverworldEditor::ApplyZSCustomOverworldASM(int target_version) {
RETURN_IF_ERROR(UpdateROMVersionMarkers(target_version));
// Log symbols found during patching
LOG_INFO("OverworldEditor", "ASM patch applied successfully. Found %zu symbols:",
LOG_DEBUG("OverworldEditor", "ASM patch applied successfully. Found %zu symbols:",
result.symbols.size());
for (const auto& symbol : result.symbols) {
LOG_INFO("OverworldEditor", " %s @ $%06X", symbol.name.c_str(),
LOG_DEBUG("OverworldEditor", " %s @ $%06X", symbol.name.c_str(),
symbol.address);
}
// Refresh overworld data to reflect changes
RETURN_IF_ERROR(overworld_.Load(rom_));
LOG_INFO("OverworldEditor", "ZSCustomOverworld v%d successfully applied to ROM",
LOG_DEBUG("OverworldEditor", "ZSCustomOverworld v%d successfully applied to ROM",
target_version);
return absl::OkStatus();
@@ -2618,7 +2618,7 @@ absl::Status OverworldEditor::UpdateROMVersionMarkers(int target_version) {
(*rom_)[zelda3::OverworldCustomAreaSpecificBGEnabled] = 0x01;
(*rom_)[zelda3::OverworldCustomMainPaletteEnabled] = 0x01;
LOG_INFO("OverworldEditor", "Enabled v2+ features: Custom BG colors, Main palettes");
LOG_DEBUG("OverworldEditor", "Enabled v2+ features: Custom BG colors, Main palettes");
}
if (target_version >= 3) {
@@ -2628,7 +2628,7 @@ absl::Status OverworldEditor::UpdateROMVersionMarkers(int target_version) {
(*rom_)[zelda3::OverworldCustomTileGFXGroupEnabled] = 0x01;
(*rom_)[zelda3::OverworldCustomMosaicEnabled] = 0x01;
LOG_INFO("OverworldEditor",
LOG_DEBUG("OverworldEditor",
"Enabled v3+ features: Subscreen overlays, Animated GFX, Tile GFX "
"groups, Mosaic");
@@ -2652,11 +2652,11 @@ absl::Status OverworldEditor::UpdateROMVersionMarkers(int target_version) {
}
}
LOG_INFO("OverworldEditor", "Initialized area size data for %zu areas",
LOG_DEBUG("OverworldEditor", "Initialized area size data for %zu areas",
large_areas.size());
}
LOG_INFO("OverworldEditor", "ROM version markers updated to v%d", target_version);
LOG_DEBUG("OverworldEditor", "ROM version markers updated to v%d", target_version);
return absl::OkStatus();
}

View File

@@ -384,7 +384,7 @@ void SettingsEditor::DrawAIAgentSettings() {
std::filesystem::path path(log_file_path);
if (std::filesystem::exists(path)) {
std::filesystem::remove(path);
LOG_INFO("Settings", "Log file cleared: %s", log_file_path);
LOG_DEBUG("Settings", "Log file cleared: %s", log_file_path);
}
}
}