Merge pull request #5135 from starfrost013/phase0

RIVA 128 preparation: Implement high-frequency timer asynchronous to guest CPU and a new logging function to detect repeated patterns of lines
This commit is contained in:
Miran Grča
2025-01-14 01:38:18 +01:00
committed by GitHub
8 changed files with 562 additions and 27 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,36 @@ static volatile atomic_int do_pause_ack = 0;
static volatile atomic_int pause_ack = 0;
#ifndef RELEASE_BUILD
static char buff[1024];
static int seen = 0;
#define LOG_SIZE_BUFFER 1024 /* Log size buffer */
static char buff[LOG_SIZE_BUFFER];
static int seen = 0;
static int suppr_seen = 1;
// Functions only used in this translation unit
void pclog_ensure_stdlog_open(void);
#endif
/*
Ensures STDLOG is open for pclog_ex and pclog_ex_cyclic
*/
void pclog_ensure_stdlog_open(void)
{
#ifndef RELEASE_BUILD
if (stdlog == NULL) {
if (log_path[0] != '\0') {
stdlog = plat_fopen(log_path, "w");
if (stdlog == NULL)
stdlog = stdout;
} else
stdlog = stdout;
}
#endif
}
/*
* Log something to the logfile or stdout.
*
@@ -269,19 +294,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 +316,8 @@ pclog_ex(const char *fmt, va_list ap)
#endif
}
void
pclog_toggle_suppr(void)
{
@@ -1427,6 +1447,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,8 @@ 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);
#endif
extern void pclog_toggle_suppr(void);
#ifdef _MSC_VER

View File

@@ -12,9 +12,11 @@
*
* Authors: Miran Grca, <mgrca8@gmail.com>
* Fred N. van Kempen, <decwiz@yahoo.com>
* Connor Hyde <mario64crashed@gmail.com, nomorestarfrost@gmail.com>
*
* Copyright 2021 Miran Grca.
* Copyright 2021 Fred N. van Kempen.
* Copyright 2025 Connor Hyde.
*/
#ifndef EMU_LOG_H
@@ -26,11 +28,16 @@
extern "C" {
# endif
#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 */
/* Function prototypes. */
extern void log_set_suppr_seen(void *priv, int suppr_seen);
extern void log_set_dev_name(void *priv, char *dev_name);
# ifdef HAVE_STDARG_H
extern void log_out(void *priv, const char *fmt, va_list);
extern void log_out_cyclic(void* priv, const char *fmt, va_list);
extern void log_fatal(void *priv, const char *fmt, ...);
# endif
extern void *log_open(char *dev_name);

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)(double real_time); // 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(void); // 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);
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);

167
src/log.c
View File

@@ -12,12 +12,15 @@
*
* Authors: Miran Grca, <mgrca8@gmail.com>
* Fred N. van Kempen, <decwiz@yahoo.com>
*
* Connor Hyde <mario64crashed@gmail.com, nomorestarfrost@gmail.com>
*
* Copyright 2021 Miran Grca.
* Copyright 2021 Fred N. van Kempen.
* Copyright 2025 Connor Hyde.
*/
#include <inttypes.h>
#include <stdarg.h>
#include <stdbool.h>
#include <stdio.h>
#include <stdint.h>
#include <stdlib.h>
@@ -36,13 +39,31 @@
#ifndef RELEASE_BUILD
typedef struct log_t {
char buff[1024];
char *dev_name;
int seen;
int suppr_seen;
char buff[1024];
char *dev_name;
int seen;
int suppr_seen;
char cyclic_buff[LOG_SIZE_BUFFER_CYCLIC_LINES][LOG_SIZE_BUFFER]; // Cyclical log buffer. This is 32kb, might calloc?
int32_t cyclic_last_line;
int32_t log_cycles;
} log_t;
extern FILE *stdlog; /* file to log output to */
// Functions only used in this translation unit
void log_ensure_stdlog_open(void);
void
log_ensure_stdlog_open(void)
{
if (stdlog == NULL) {
if (log_path[0] != '\0') {
stdlog = plat_fopen(log_path, "w");
if (stdlog == NULL)
stdlog = stdout;
} else
stdlog = stdout;
}
}
void
log_set_suppr_seen(void *priv, int suppr_seen)
@@ -91,14 +112,7 @@ log_out(void *priv, const char *fmt, va_list ap)
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;
}
log_ensure_stdlog_open();
vsprintf(temp, fmt, ap);
if (log->suppr_seen && !strcmp(log->buff, temp))
@@ -117,6 +131,131 @@ log_out(void *priv, const char *fmt, va_list ap)
fflush(stdlog);
}
/*
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
log_out_cyclic(void* priv, const char* fmt, va_list ap)
{
#ifndef RELEASE_BUILD
// get our new logging system instance.
log_t* log = (log_t*)priv;
// does the log actually exist?
if (!log)
return;
// is the string empty?
if (fmt[0] == '\0')
return;
// ensure stdlog is open
log_ensure_stdlog_open();
char temp[LOG_SIZE_BUFFER] = {0};
log->cyclic_last_line %= LOG_SIZE_BUFFER_CYCLIC_LINES;
vsprintf(temp, fmt, ap);
log_copy(log, log->cyclic_buff[log->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 (log->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 + log->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 (log->cyclic_last_line % repeat_order == 0)
{
log->log_cycles++;
if (log->log_cycles == 1)
{
// 'Replay' the last few log entries so they actually show up
// Todo: is this right?
for (uint32_t index = log->cyclic_last_line - 1; index > (log->cyclic_last_line - repeat_order); index--)
{
// *very important* to prevent out of bounds index
uint32_t real_index = index % LOG_SIZE_BUFFER_CYCLIC_LINES;
log_copy(log, temp, log->cyclic_buff[real_index], LOG_SIZE_BUFFER);
fprintf(stdlog, "%s", log->cyclic_buff[real_index]);
}
// restore the original line
log_copy(log, temp, log->cyclic_buff[log->cyclic_last_line], LOG_SIZE_BUFFER);
fprintf(stdlog, "%s", temp); // allow normal logging
}
if (log->log_cycles > 1 && log->log_cycles < 100)
fprintf(stdlog, "***** Cyclical Log Repeat of Order %d #%d *****\n", repeat_order, log->log_cycles);
else if (log->log_cycles == 100)
fprintf(stdlog, "Logged the same cycle 100 times...shutting up until something interesting happens\n");
}
}
else
{
log->log_cycles = 0;
fprintf(stdlog, "%s", temp);
}
log->cyclic_last_line++;
#endif
}
void
log_fatal(void *priv, const char *fmt, ...)
{
@@ -145,6 +284,8 @@ log_open(char *dev_name)
log->dev_name = dev_name;
log->suppr_seen = 1;
log->cyclic_last_line = 0;
log->log_cycles = 0;
return (void *) log;
}

View File

@@ -4,6 +4,7 @@
#include <wchar.h>
#include <86box/86box.h>
#include <86box/timer.h>
#include <86box/nv/vid_nv_rivatimer.h>
uint64_t TIMER_USEC;
uint32_t timer_target;
@@ -168,6 +169,9 @@ timer_init(void)
timer_target = 0ULL;
tsc = 0;
/* Initialise the CPU-independent timer */
rivatimer_init();
timer_inited = 1;
}

View File

@@ -27,7 +27,9 @@ add_library(vid OBJECT agpgart.c video.c vid_table.c vid_cga.c vid_cga_comp.c
vid_tkd8001_ramdac.c vid_att20c49x_ramdac.c vid_s3.c vid_s3_virge.c
vid_ibm_rgb528_ramdac.c vid_sdac_ramdac.c vid_ogc.c vid_mga.c vid_nga.c
vid_tvp3026_ramdac.c vid_att2xc498_ramdac.c vid_xga.c
vid_bochs_vbe.c)
vid_bochs_vbe.c
nv/nv_rivatimer.c
)
if(G100)
target_compile_definitions(vid PRIVATE USE_G100)

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(void)
{
// 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.");
// 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(void)
{
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.");
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.");
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.");
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.");
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.");
rivatimer_ptr->period = period;
}