Step 0333: Diagnostic-Based Rendering Correction

Summary

This step implements critical fixes to the logger configuration and diagnostic code to identify where color information is lost in the rendering pipeline. Added Explicit logger configuration to ensure that INFO level logs appear correctly, logs were implemented withprint()as a fallback to guarantee visibility, and improved the diagnostic code to run both when the framebuffer is received as a parameter as when obtained directly from the PPU.

Hardware Concept

Python Rendering Pipeline

The rendering pipeline in Viboy Color follows this sequence:

1. C++ (PPU): Write color indices (0-3) to the framebuffer
2. Cython: Expose the framebuffer as memoryview
3. Python (viboy.py): Copy framebuffer to bytearray (immutable snapshot)
4. Python (renderer.py): Convert indices to RGB using the palette
5. Pygame: Draw RGB pixels on the screen

The problem identified in Step 0332 is that the C++ framebuffer contains correct data (80/160 non-white pixels according to C++ logs), but the screen shows completely white. This suggests that color information is lost somewhere in the Python pipeline.

Logger Configuration

The Python logger must be configured correctly to display INFO level logs. If the logger is not configured or is configured with a higher level (WARNING, ERROR), The diagnostic logs will not appear, making it impossible to identify where the information is lost.

Implementation

1. Explicit Logger Configuration

Added explicit logger configuration insrc/viboy.pyto ensure that INFO level logs appear correctly:

# --- Step 0333: Configuración Explícita del Logger ---
# Asegurar que el logger muestra logs de nivel INFO
logging.basicConfig(
    level=logging.INFO,
    format='%(levelname)s: %(message)s',
    force=True  # Forzar reconfiguración si ya estaba configurado
)
# -------------------------------------------

The parameterforce=Trueensures that the configuration is applied even if the logger It was already configured previously.

2. Logs with print() as Fallback

Logs were added withprint()in addition tologger.info()to ensure so that the logs appear even if there are problems with the logger configuration:

# --- Step 0333: Logs with print() as fallback ---
log_msg = f"[Renderer-Framebuffer-Diagnostic] Frame {self._framebuffer_diagnostic_count} | ..."
print(log_msg) # Fallback to print()
logger.info(log_msg) # Normal logger
# -------------------------------------------

3. Diagnostic Code Execution Verification

Added input logs to the diagnostic code to verify that it is running correctly. The code now checks both when the framebuffer is received as a parameter and when it is obtained directly from the PPU:

# --- STEP 0333: Diagnostic Code Execution Verification ---
if framebuffer_data is not None:
    print(f"[Renderer-Diagnostic-Entry] Framebuffer received as parameter, length: {len(framebuffer_data)}")
    logger.info(f"[Renderer-Diagnostic-Entry] Framebuffer received as parameter, length: {len(framebuffer_data)}")
    diagnostic_data = framebuffer_data
else:
    # Get from PPU and verify
    if frame_indices is not None:
        print(f"[Renderer-Diagnostic-Entry] Framebuffer obtained from PPU, length: {len(frame_indices)}")
        logger.info(f"[Renderer-Diagnostic-Entry] Framebuffer obtained from PPU, length: {len(frame_indices)}")
        diagnostic_data = frame_indices
# -------------------------------------------

4. Pixel Drawing Check

Added logs at the pixel draw point to verify that RGB colors are correct before drawing them:

# --- STEP 0333: Pixel Drawing Verification ---
if self._pixel_draw_check_count< 5:
    self._pixel_draw_check_count += 1
    test_pixels = [(0, 0), (80, 72), (159, 143)]
    for x, y in test_pixels:
        idx = y * 160 + x
        if idx < len(frame_indices):
            color_index = frame_indices[idx] & 0x03
            rgb_color = palette[color_index]
            print(f"[Renderer-Pixel-Draw] Pixel ({x}, {y}): index={color_index} ->RGB={rgb_color}")
            logger.info(f"[Renderer-Pixel-Draw] Pixel ({x}, {y}): index={color_index} -> RGB={rgb_color}")
# -------------------------------------------

Design Decisions

• Double logging (print + logger): It is used so muchprint()aslogger.info()to ensure that the logs appear even if there are problems with the logger configuration.
• diagnostic_data variable: A variable is useddiagnostic_datawhat can it beframebuffer_dataeitherframe_indicesto unify the diagnosis code.
• Log limit: Diagnostic logs are limited to the first 5 frames to avoid cluttering the context.

Affected Files

• src/viboy.py- Explicit configuration of the logger and logs with print() as fallback
• src/gpu/renderer.py- Pixel drawing verification and diagnostic code improvements

Tests and Verification

The C++ module was recompiled and tests were run with the 5 ROMs according to the plan:

• Compilation:C++ module successfully recompiled without errors
• Evidence:Tests were run with the 5 ROMs (pkmn.gb, tetris.gb, mario.gbc, pkmn-amarillo.gb, Oro.gbc)
• Logs:Diagnostic logs now appear correctly with explicit logger configuration

Compile command:

python3 setup.py build_ext --inplace

Test command (example):

timeout 150 python3 main.py roms/pkmn.gb 2>&1 | tee logs/test_pkmn_step0333.log

Sources consulted

• Python Logging Documentation:https://docs.python.org/3/library/logging.html
• Step 0332: Framebuffer Rendering Investigation and Fix (previous)

Educational Integrity

Next Steps

• [ ] Analyze diagnostic logs from the 5 ROMs to identify where color information is lost
• [ ] Implement specific fix based on log findings
• [ ] Verify that the temporary checkerboard is displayed correctly on all ROMs
• [ ] Step 0334: Final rendering check or deeper analysis based on results