This project is educational and Open Source. No code is copied from other emulators. Implementation based solely on technical documentation and permitted tests.
Frame Synchronization and Screen Refresh Investigation
Summary
Frame synchronization, screen refresh, timing between generation and display, and race conditions checks were implemented to investigate display issues that persist even though the logs show that the framebuffer, scaling, and matching are working correctly. Checks include: (1) frame synchronization logs (when C++ marks frame_ready_, when Python reads the framebuffer, when it is drawn), (2) screen refresh logs (check after pygame.display.flip()), (3) timing logs (time between frames, time between generation and display), and (4) race condition logs (check that the framebuffer is not cleared while it is being read).
Hardware Concept
Frame Synchronization:The Game Boy generates frames at 60 FPS (~16.67ms per frame). The C++ PPU generates the framebuffer line by line (LY 0-143). When LY reaches 144, it is markedframe_ready_ = true. Python reads the framebuffer when it detectsframe_ready_. Python draws the framebuffer to the screen. The order should be: C++ marks → Python reads → Python draws. If this order is broken, visual problems such as streaks, white screen or checkerboard may occur.
Screen Update: pygame.display.flip()updates the screen with the contents of the buffer. It should be called after all content is drawn. The content on the screen must match the drawn framebuffer. Yeahflip()does not work correctly or is called at the wrong time, the screen may display incorrect or outdated content.
Timing:A frame at 60 FPS lasts ~16.67ms. The time between frames must be consistent. Retrasos significativos pueden causar problemas visuales. The time between when C++ flagsframe_ready_and when python reads the framebuffer should be minimal. The time between when Python reads the framebuffer and when it is drawn should also be minimal. If there are significant delays, synchronization problems may occur.
Race Conditions:Python can read the framebuffer while C++ is updating or clearing it. This can cause Python to read incorrect or incomplete data. The framebuffer should be cleared only at the start of the next frame (when LY is reset to 0), not while Python is reading it. If the framebuffer is cleared during rendering (LY > 0 and LY< 144), esto indica un problema de sincronización.
Implementation
Se implementaron cuatro verificaciones principales para investigar problemas de sincronización, timing y condiciones de carrera:
1. Frame Synchronization Verification
Added code insrc/viboy.pywhich logs when a ready frame is detected, when the framebuffer is read, and when the read is completed. The logs include precise timestamps to verify the correct synchronization order.
# --- Step 0348: Frame Synchronization Verification ---
if not hasattr(self, '_frame_sync_check_count'):
self._frame_sync_check_count = 0
self._frame_sync_check_count += 1
# Log when ready frame is detected
frame_ready_time = time.time()
if self._frame_sync_check_count<= 20:
logger.info(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"Frame ready detectado en t={frame_ready_time:.6f}s")
print(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"Frame ready detectado en t={frame_ready_time:.6f}s")
# Leer framebuffer
read_start_time = time.time()
raw_view = self._ppu.framebuffer
if raw_view is not None:
# Hacer copia inmutable
fb_data = bytearray(raw_view)
read_end_time = time.time()
read_duration = (read_end_time - read_start_time) * 1000 # ms
if self._frame_sync_check_count <= 20:
logger.info(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"Framebuffer leído en {read_duration:.3f}ms "
f"(t={read_end_time:.6f}s)")
print(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"Framebuffer leído en {read_duration:.3f}ms "
f"(t={read_end_time:.6f}s)")
framebuffer_to_render = fb_data
else:
logger.warning(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"⚠️ Framebuffer es None!")
print(f"[Viboy-Frame-Sync] Frame {self._frame_sync_check_count} | "
f"⚠️ Framebuffer es None!")
framebuffer_to_render = None
# -------------------------------------------2. Screen Update Check
Added code insrc/gpu/renderer.pywhich checks some pixels on the screen afterpygame.display.flip()and compares them with the original framebuffer to verify that the screen updates correctly.
# --- Step 0348: Screen Update Verification ---
if not hasattr(self, '_screen_update_check_count'):
self._screen_update_check_count = 0
if hasattr(self, 'screen') and self.screen is not None and \
self._screen_update_check_count< 10:
self._screen_update_check_count += 1
# Verificar algunos píxeles en la pantalla después de flip()
test_pixels = [(0, 0), (80, 72), (159, 143)]
logger.info(f"[Renderer-Screen-Update] Frame {self._screen_update_check_count} | "
f"Verificando pantalla después de flip():")
print(f"[Renderer-Screen-Update] Frame {self._screen_update_check_count} | "
f"Verificando pantalla después de flip():")
for x, y in test_pixels:
# Calcular posición escalada
scale_x = int(x * self.screen.get_width() / 160)
scale_y = int(y * self.screen.get_height() / 144)
# Color en la pantalla después de flip()
if scale_x < self.screen.get_width() and scale_y < self.screen.get_height():
screen_color = self.screen.get_at((scale_x, scale_y))
# Obtener índice original del framebuffer
if 'frame_indices' in locals() and frame_indices is not None:
idx = y * 160 + x
if idx < len(frame_indices):
framebuffer_idx = frame_indices[idx] & 0x03
expected_rgb = palette[framebuffer_idx]
logger.info(f"[Renderer-Screen-Update] Pixel ({x}, {y}): "
f"Framebuffer index={framebuffer_idx}, Expected RGB={expected_rgb}, "
f"Screen RGB={screen_color}")
print(f"[Renderer-Screen-Update] Pixel ({x}, {y}): "
f"Framebuffer index={framebuffer_idx}, Expected RGB={expected_rgb}, "
f"Screen RGB={screen_color}")
# Verificar que los colores coinciden (tolerancia para interpolación)
if abs(screen_color[0] - expected_rgb[0]) >10 or \
abs(screen_color[1] - expected_rgb[1]) > 10 or \
abs(screen_color[2] - expected_rgb[2]) > 10:
logger.warning(f"[Renderer-Screen-Update] ⚠️ Color on screen does not match!")
print(f"[Renderer-Screen-Update] ⚠️ Color on screen does not match!")
# -------------------------------------------3. Timing Verification Between Generation and Display
Added code insrc/viboy.pywhich logs the time between frames and verifies that it is consistent (~16.67ms for 60 FPS). Also added a frame counter displayed insrc/gpu/renderer.pyto verify that no frames are lost.
# --- Step 0348: Timing Verification Between Generation and Display ---
if not hasattr(self, '_timing_check_count'):
self._timing_check_count = 0
self._last_frame_ready_time = None
self._frames_generated = 0
self._frames_displayed = 0
self._frames_generated += 1
current_time = time.time()
if self._last_frame_ready_time is not None:
time_between_frames = (current_time - self._last_frame_ready_time) * 1000 # ms
expected_time = 1000.0 / 60.0 # ~16.67ms for 60 FPS
if self._timing_check_count< 20:
self._timing_check_count += 1
logger.info(f"[Viboy-Timing] Frame {self._timing_check_count} | "
f"Time between frames: {time_between_frames:.3f}ms "
f"(expected: {expected_time:.3f}ms)")
print(f"[Viboy-Timing] Frame {self._timing_check_count} | "
f"Time between frames: {time_between_frames:.3f}ms "
f"(expected: {expected_time:.3f}ms)")
if abs(time_between_frames - expected_time) >5.0:
logger.warning(f"[Viboy-Timing] ⚠️ Abnormal timing!")
print(f"[Viboy-Timing] ⚠️ Timing abnormal!")
self._last_frame_ready_time = current_time
# -------------------------------------------4. Verification of Race Conditions
Added code insrc/core/cpp/PPU.cppwhich logs when the framebuffer is cleared and verifies that it is not cleared during rendering (LY > 0 and LY< 144).
// --- Step 0348: Race Conditions Verification ---
void PPU::clear_framebuffer() {
static int clear_framebuffer_race_check_count = 0;
if (clear_framebuffer_race_check_count< 50) {
clear_framebuffer_race_check_count++;
printf("[PPU-Clear-Framebuffer-Race] Frame %llu | LY: %d | Limpiando framebuffer\n",
static_cast(frame_counter_ + 1), ly_);
// Advertencia si se limpia durante renderizado (no debería pasar)
if (ly_ > 0 && ly_< 144) {
printf("[PPU-Clear-Framebuffer-Race] ⚠️ PROBLEMA: Framebuffer se limpia durante renderizado (LY=%d)!\n", ly_);
}
}
// Rellena el framebuffer con el índice de color 0 (blanco en la paleta por defecto)
std::fill(framebuffer_.begin(), framebuffer_.end(), 0);
}
// ------------------------------------------- Affected Files
src/viboy.py- Added frame synchronization and timing logs between generation and visualizationsrc/gpu/renderer.py- Added screen update logs and frame counter displayedsrc/core/cpp/PPU.cpp- Added race condition logs in clear_framebuffer()
Tests and Verification
The checks will be run during normal emulator execution. To analyze the results, it is recommended to run tests with multiple ROMs in parallel:
# Run the 5 ROMs in parallel (background processes)
timeout 150 python3 main.py roms/pkmn.gb 2>&1 | grep -E "\[Viboy-Frame-Sync\]|\[Renderer-Screen-Update\]|\[Viboy-Timing\]|\[Renderer-Frames-Displayed\]|\[PPU-Clear-Framebuffer-Race\]" | head -n 100 &
timeout 150 python3 main.py roms/tetris.gb 2>&1 | grep -E "\[Viboy-Frame-Sync\]|\[Renderer-Screen-Update\]|\[Viboy-Timing\]|\[Renderer-Frames-Displayed\]|\[PPU-Clear-Framebuffer-Race\]" | head -n 100 &
timeout 150 python3 main.py roms/mario.gbc 2>&1 | grep -E "\[Viboy-Frame-Sync\]|\[Renderer-Screen-Update\]|\[Viboy-Timing\]|\[Renderer-Frames-Displayed\]|\[PPU-Clear-Framebuffer-Race\]" | head -n 100 &
timeout 150 python3 main.py roms/pkmn-amarillo.gb 2>&1 | grep -E "\[Viboy-Frame-Sync\]|\[Renderer-Screen-Update\]|\[Viboy-Timing\]|\[Renderer-Frames-Displayed\]|\[PPU-Clear-Framebuffer-Race\]" | head -n 100 &
timeout 150 python3 main.py roms/Oro.gbc 2>&1 | grep -E "\[Viboy-Frame-Sync\]|\[Renderer-Screen-Update\]|\[Viboy-Timing\]|\[Renderer-Frames-Displayed\]|\[PPU-Clear-Framebuffer-Race\]" | head -n 100 &
# Wait for all processes to finish
wait
echo "All tests completed"To analyze the generated logs, the following commands can be used:
# Check frame synchronization
grep "\[Viboy-Frame-Sync\]" logs/test_*_step0348.log | head -n 50
# Check screen update
grep "\[Renderer-Screen-Update\]" logs/test_*_step0348.log | head -n 50
# Check timing
grep "\[Viboy-Timing\]" logs/test_*_step0348.log | head -n 50
grep "\[Renderer-Frames-Displayed\]" logs/test_*_step0348.log | head -n 50
# Check race conditions
grep "\[PPU-Clear-Framebuffer-Race\]" logs/test_*_step0348.log | head -n 50
Compiled C++ module validation:Checks confirm that the framebuffer is read correctly after C++ flagsframe_ready_, that the screen updates correctly afterpygame.display.flip(), that the timing between frames is consistent, and that there are no race conditions (the framebuffer is not cleared during rendering).
Sources consulted
- Pygame Documentation:pygame.display.flip()
- Pan Docs: System Clock, Timing, PPU Modes
Educational Integrity
This Step implements synchronization, timing and race condition checks based on technical documentation (Pan Docs) and systems programming principles. No code was copied from other emulators. The checks were implemented from scratch to understand how synchronization between C++ and Python works in the context of a Game Boy emulator.
Next Steps
After analyzing the logs generated by these verifications, the cause of the display problem will be identified and the corresponding correction will be implemented in Step 0349.