Implement the rivatimer and cyclical logging from my main NV3 branch so that we can get it reviewed and merged.

This commit is contained in:
starfrost013
2025-01-12 15:21:31 +00:00
parent 226537145d
commit 204b24022f
4 changed files with 502 additions and 13 deletions

View File

@@ -103,6 +103,7 @@
#include <86box/machine_status.h>
#include <86box/apm.h>
#include <86box/acpi.h>
#include <86box/nv/vid_nv_rivatimer.h>
// Disable c99-designator to avoid the warnings about int ng
#ifdef __clang__
@@ -252,12 +253,37 @@ static volatile atomic_int do_pause_ack = 0;
static volatile atomic_int pause_ack = 0;
#ifndef RELEASE_BUILD
static char buff[1024];
#define LOG_SIZE_BUFFER 1024 /* Log size buffer */
#define LOG_SIZE_BUFFER_CYCLIC_LINES 32 /* Cyclic log size buffer (number of lines that should be cehcked) */
#define LOG_MINIMUM_REPEAT_ORDER 4 /* Minimum repeat size */
static char buff[LOG_SIZE_BUFFER];
static char cyclic_buff[LOG_SIZE_BUFFER_CYCLIC_LINES][LOG_SIZE_BUFFER];
static int32_t cyclic_last_line = 0;
static int32_t log_cycles = 0;
static int seen = 0;
static int suppr_seen = 1;
#endif
/*
Ensures STDLOG is open for pclog_ex and pclog_ex_cyclic
*/
void
pclog_ensure_stdlog_open()
{
if (stdlog == NULL) {
if (log_path[0] != '\0') {
stdlog = plat_fopen(log_path, "w");
if (stdlog == NULL)
stdlog = stdout;
} else
stdlog = stdout;
}
}
/*
* Log something to the logfile or stdout.
*
@@ -269,19 +295,12 @@ void
pclog_ex(const char *fmt, va_list ap)
{
#ifndef RELEASE_BUILD
char temp[1024];
char temp[LOG_SIZE_BUFFER];
if (strcmp(fmt, "") == 0)
return;
if (stdlog == NULL) {
if (log_path[0] != '\0') {
stdlog = plat_fopen(log_path, "w");
if (stdlog == NULL)
stdlog = stdout;
} else
stdlog = stdout;
}
pclog_ensure_stdlog_open();
vsprintf(temp, fmt, ap);
if (suppr_seen && !strcmp(buff, temp))
@@ -298,6 +317,114 @@ pclog_ex(const char *fmt, va_list ap)
#endif
}
/*
Starfrost, 7-8 January 2025:
For RIVA 128 emulation I needed a way to suppress logging if a repeated pattern of the same set of lines were found.
Implements a version of the Rabin-Karp algorithm https://en.wikipedia.org/wiki/Rabin%E2%80%93Karp_algorithm
*/
void
pclog_ex_cyclic(const char* fmt, va_list ap)
{
#ifndef RELEASE_BUILD
char temp[LOG_SIZE_BUFFER];
cyclic_last_line %= LOG_SIZE_BUFFER_CYCLIC_LINES;
vsprintf(temp, fmt, ap);
pclog_ensure_stdlog_open();
strncpy(cyclic_buff[cyclic_last_line], temp, LOG_SIZE_BUFFER);
uint32_t hashes[LOG_SIZE_BUFFER_CYCLIC_LINES] = {0};
// Random numbers
uint32_t base = 257;
uint32_t mod = 1000000007;
uint32_t repeat_order = 0;
bool is_cycle = false;
// compute the set of hashes for the current log buffer
for (int32_t log_line = 0; log_line < LOG_SIZE_BUFFER_CYCLIC_LINES; log_line++)
{
if (cyclic_buff[log_line][0] == '\0')
continue; // skip
for (int32_t log_line_char = 0; log_line_char < LOG_SIZE_BUFFER; log_line_char++)
{
hashes[log_line] = hashes[log_line] * base + cyclic_buff[log_line][log_line_char] % mod;
}
}
// Now see if there are real cycles...
// We implement a minimum repeat size.
for (int32_t check_size = LOG_MINIMUM_REPEAT_ORDER; check_size < LOG_SIZE_BUFFER_CYCLIC_LINES / 2; check_size++)
{
//TODO: Log what we need for cycle 1.
//TODO: Command line option that lets us turn off this behaviour.
for (int32_t log_line_to_check = 0; log_line_to_check < check_size; log_line_to_check++)
{
if (hashes[log_line_to_check] == hashes[(log_line_to_check + check_size) % LOG_SIZE_BUFFER_CYCLIC_LINES])
{
repeat_order = check_size;
break;
}
}
is_cycle = (repeat_order != 0);
// if there still is a cycle..
if (is_cycle)
break;
}
if (is_cycle)
{
if (cyclic_last_line % repeat_order == 0)
{
log_cycles++;
if (log_cycles == 1)
{
// 'Replay' the last few log entries so they actually show up
// Todo: is this right?
for (uint32_t index = cyclic_last_line - 1; index > (cyclic_last_line - repeat_order); index--)
{
// *very important* to prevent out of bounds index
uint32_t real_index = index % LOG_SIZE_BUFFER_CYCLIC_LINES;
fprintf(stdlog, "%s", temp);
}
fprintf(stdlog, "%s", temp); // allow normal logging
}
if (log_cycles > 1 && log_cycles < 100)
fprintf(stdlog, "***** Cyclical Log Repeat of Order %d #%d *****\n", repeat_order, log_cycles);
else if (log_cycles == 100)
fprintf(stdlog, "Logged the same cycle 100 times...shutting up until something interesting happens\n");
}
}
else
{
log_cycles = 0;
fprintf(stdlog, "%s", temp);
}
cyclic_last_line++;
#endif
}
void
pclog_toggle_suppr(void)
{
@@ -1427,6 +1554,9 @@ pc_run(void)
pc_reset_hard_init();
}
/* Update the guest-CPU independent timer for devices with independent clock speed */
rivatimer_update_all();
/* Run a block of code. */
startblit();
cpu_exec((int32_t) cpu_s->rspeed / 100);

View File

@@ -187,8 +187,9 @@ extern int config_changed; /* config has changed */
/* Function prototypes. */
#ifdef HAVE_STDARG_H
extern void pclog_ex(const char *fmt, va_list);
extern void fatal_ex(const char *fmt, va_list);
extern void pclog_ex(const char *fmt, va_list ap);
extern void fatal_ex(const char *fmt, va_list ap);
extern void pclog_ex_cyclic(const char* fmt, va_list ap);
#endif
extern void pclog_toggle_suppr(void);
#ifdef _MSC_VER

View File

@@ -0,0 +1,84 @@
/*
* 86Box A hypervisor and IBM PC system emulator that specializes in
* running old operating systems and software designed for IBM
* PC systems and compatibles from 1981 through fairly recent
* system designs based on the PCI bus.
*
* This file is part of the 86Box distribution.
*
* Fast, high-frequency, guest CPU-independent timer for Riva emulation.
*
*
* Authors: Connor Hyde, <mario64crashed@gmail.com> I need a better email address ;^)
*
* Copyright 2024-2025 starfrost
*/
/*
RivaTimer
This is a fast, high-frequency, guest CPU-independent timer.
The main 86box timer is dependent on the TSC (time-stamp counter) register of the emulated CPU core.
This is fine for most purposes and has advantages in the fields of synchronisation and integrates neatly with
the clock dividers of the PC architecture, but in the case of the RIVA 128 it does not particularly suffice
(although it can be made to work with various techniques) since the clock source on the RIVA 128 is on the board itself
and the GPU has several different clocks that control different parts of the GPU (e.g., PTIMER runs on the memory clock but the core gpu is using the pixel clock).
As faster graphics cards that offload more and more of the 3D graphics pipeline are emulated in the future, more and more work needs to be done by the emulator and
issues of synchronisation with a host CPU will simply make that work harder. Some features that are required for
Architecture Brand Name 3D Features
NV1 (1995) NV1 Some weird URBS rectangle crap but feature set generally similar to nv3 but a bit worse
NV3 (1997) RIVA 128 (ZX) Triangle setup, edge-slope calculations, edge interpolation, span-slope calculations, span interpolation (Color-buffer, z-buffer, texture mapping, filtering)
NV4 (1998) RIVA TNT NV3 + 2x1 pixel pipelines + 32-bit colour + larger textures + trilinear + more ram (16mb)
NV5 (1999) RIVA TNT2 NV4 + higher clock speed
NV10 (1999) GeForce 256 NV5 + initial geometry transformation + lighting (8x lights) + MPEG-2 motion compensation + 4x1 pixel pipelines
NV15 (2000) GeForce 2 NV10 + First attempt at programmability + 4x2 pixel pipelines
NV20 (2001) GeForce 3 Programmable shaders!
As you can see, the performance basically exponentially increases over a period of only 4 years.
So I decided to create this timer that is completely separate from the CPU Core.
*/
#pragma once
#include <stdlib.h>
#include <stdint.h>
#include <stdbool.h>
#include <stdio.h>
#include <86Box\86box.h>
#ifdef _WIN32
#include <Windows.h>
// Linux & MacOS should have the same API since OSX 10.12
#else
#include <time.h>
#endif
typedef struct rivatimer_s
{
struct rivatimer_s* prev; // Previous Rivatimer
double period; // Period in uS before firing
double value; // The current value of the rivatimer
bool running; // Is this RivaTimer running?
struct rivatimer_s* next; // Next RivaTimer
void (*callback)(); // Callback to call on fire
#ifdef _WIN32
LARGE_INTEGER starting_time; // Starting time.
#else
struct timespec starting_time; // Starting time.
#endif
double time; // Accumulated time in uS.
} rivatimer_t;
void rivatimer_init(); // Initialise the Rivatimer.
rivatimer_t* rivatimer_create(double period, void (*callback)(double real_time));
void rivatimer_destroy(rivatimer_t* rivatimer_ptr);
void rivatimer_update_all();
void rivatimer_start(rivatimer_t* rivatimer_ptr);
void rivatimer_stop(rivatimer_t* rivatimer_ptr);
double rivatimer_get_time(rivatimer_t* rivatimer_ptr);
void rivatimer_set_callback(rivatimer_t* rivatimer_ptr, void (*callback)(double real_time));
void rivatimer_set_period(rivatimer_t* rivatimer_ptr, double period);

274
src/video/nv/nv_rivatimer.c Normal file
View File

@@ -0,0 +1,274 @@
/*
* 86Box A hypervisor and IBM PC system emulator that specializes in
* running old operating systems and software designed for IBM
* PC systems and compatibles from 1981 through fairly recent
* system designs based on the PCI bus.
*
* This file is part of the 86Box distribution.
*
* Fast, high-frequency, CPU-independent timer.
*
*
*
* Authors: Connor Hyde, <mario64crashed@gmail.com> I need a better email address ;^)
*
* Copyright 2024-2025 starfrost
*/
/* See vid_nv_rivatimer.h comments for rationale behind not using the regular timer system
Notes applicable to this file:
Since Windows XP, QueryPerformanceCounter and QueryPerformanceFrequency cannot fail so they are not checked.
*/
#include <86Box/nv/vid_nv_rivatimer.h>
#ifdef _WIN32
LARGE_INTEGER performance_frequency;
#endif
rivatimer_t* rivatimer_head; // The head of the rivatimer list.
rivatimer_t* rivatimer_tail; // The tail of the rivatimer list.
/* Functions only used in this translation unit */
bool rivatimer_really_exists(rivatimer_t* rivatimer); // Determine if a rivatimer really exists in the linked list.
void rivatimer_init()
{
// Destroy all the rivatimers.
rivatimer_t* rivatimer_ptr = rivatimer_head;
if (!rivatimer_ptr)
return;
while (rivatimer_ptr)
{
// since we are destroing it
rivatimer_t* old_next = rivatimer_ptr->next;
rivatimer_destroy(rivatimer_ptr);
rivatimer_ptr = old_next;
}
#ifdef _WIN32
// Query the performance frequency.
QueryPerformanceFrequency(&performance_frequency);
#endif
}
// Creates a rivatimer.
rivatimer_t* rivatimer_create(double period, void (*callback)(double real_time))
{
rivatimer_t* new_rivatimer = NULL;
// See i
if (period <= 0
|| !callback)
{
fatal("Invalid rivatimer_create call: period <= 0 or no callback");
}
// If there are no rivatimers, create one
if (!rivatimer_head)
{
rivatimer_head = calloc(1, sizeof(rivatimer_t));
rivatimer_head->prev = NULL; // indicate this is the first in the list even if we don't strictly need to
rivatimer_tail = rivatimer_head;
new_rivatimer = rivatimer_head;
}
else // Otherwise add a new one to the list
{
rivatimer_tail->next = calloc(1, sizeof(rivatimer_t));
rivatimer_tail = rivatimer_tail->next;
new_rivatimer = rivatimer_tail;
}
// sanity check
if (new_rivatimer)
{
new_rivatimer->running = false;
new_rivatimer->period = period;
new_rivatimer->next = NULL; // indicate this is the last in the list
new_rivatimer->callback = callback;
}
return new_rivatimer;
}
// Determines if a rivatimer really exists.
bool rivatimer_really_exists(rivatimer_t* rivatimer)
{
rivatimer_t* current = rivatimer_head;
if (!current)
return false;
while (current)
{
if (current == rivatimer)
return true;
current = current->next;
}
return false;
}
// Destroy a rivatimer.
void rivatimer_destroy(rivatimer_t* rivatimer_ptr)
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_destroy: The timer was already destroyed, or never existed in the first place. Punch starfrost in the face");
// Case: We are destroying the head
if (rivatimer_ptr == rivatimer_head)
{
// This is the only rivatimer
if (rivatimer_ptr->next == NULL)
{
rivatimer_head = NULL;
rivatimer_tail = NULL;
}
// This is not the only rivatimer
else
{
rivatimer_head = rivatimer_ptr->next;
rivatimer_head->prev = NULL;
// This is the only rivatimer and now there is only one
if (!rivatimer_head->next)
rivatimer_tail = rivatimer_head;
}
}
// Case: We are destroying the tail
else if (rivatimer_ptr == rivatimer_tail)
{
// We already covered the case where there is only one item above
rivatimer_tail = rivatimer_ptr->prev;
rivatimer_tail->next = NULL;
}
// Case: This is not the first or last rivatimer, so we don't need to set the head or tail
else
{
// Fix the break in the chain that this
if (rivatimer_ptr->next)
rivatimer_ptr->prev->next = rivatimer_ptr->next;
if (rivatimer_ptr->prev)
rivatimer_ptr->next->prev = rivatimer_ptr->prev;
}
free(rivatimer_ptr);
rivatimer_ptr = NULL; //explicitly set to null
}
void rivatimer_update_all()
{
rivatimer_t* rivatimer_ptr = rivatimer_head;
if (!rivatimer_ptr)
return;
while (rivatimer_ptr)
{
// if it's not running skip it
if (!rivatimer_ptr->running)
{
rivatimer_ptr = rivatimer_ptr->next;
continue;
}
#ifdef _WIN32
LARGE_INTEGER current_time;
QueryPerformanceCounter(&current_time);
double microseconds = ((double)current_time.QuadPart / 1000000.0) - (rivatimer_ptr->starting_time.QuadPart / 1000000.0);
#else
struct timespec current_time;
clock_gettime(CLOCK_REALTIME, &current_time);
double microseconds = ((double)current_time.tv_sec * 1000000.0) + ((double)current_time.tv_nsec / 1000.0);
#endif
rivatimer_ptr->time += microseconds;
// Reset the current time so we can actually restart
#ifdef _WIN32
QueryPerformanceCounter(&rivatimer_ptr->starting_time);
#else
clock_gettime(CLOCK_REALTIME, &rivatimer_ptr->starting_time);
#endif
// Time to fire
if (microseconds > rivatimer_ptr->period)
{
if (!rivatimer_ptr->callback)
{
pclog("Eh? No callback in RivaTimer?");
continue;
}
rivatimer_ptr->callback(microseconds);
}
rivatimer_ptr = rivatimer_ptr->next;
}
}
void rivatimer_start(rivatimer_t* rivatimer_ptr)
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_start: The timer has been destroyed, or never existed in the first place. Punch starfrost in the face");
if (rivatimer_ptr->period <= 0)
fatal("rivatimer_start: Zero period!");
rivatimer_ptr->running = true;
// Start off so rivatimer_update_all can actually update.
#ifdef _WIN32
QueryPerformanceCounter(&rivatimer_ptr->starting_time);
#else
clock_gettime(CLOCK_REALTIME, &rivatimer_ptr->starting_time);
#endif
}
void rivatimer_stop(rivatimer_t* rivatimer_ptr)
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_stop: The timer has been destroyed, or never existed in the first place. Punch starfrost in the face");
rivatimer_ptr->running = false;
rivatimer_ptr->time = 0;
}
// Get the current time value of a rivatimer
double rivatimer_get_time(rivatimer_t* rivatimer_ptr)
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_get_time: The timer has been destroyed, or never existed in the first place. Punch starfrost in the face");
return rivatimer_ptr->time;
}
void rivatimer_set_callback(rivatimer_t* rivatimer_ptr, void (*callback)(double real_time))
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_set_callback: The timer has been destroyed, or never existed in the first place. Punch starfrost in the face");
if (!callback)
fatal("rivatimer_set_callback: No callback!");
rivatimer_ptr->callback = callback;
}
void rivatimer_set_period(rivatimer_t* rivatimer_ptr, double period)
{
if (!rivatimer_really_exists(rivatimer_ptr))
fatal("rivatimer_set_period: The timer has been destroyed, or never existed in the first place. Punch starfrost in the face");
rivatimer_ptr->period = period;
}