| Re: [hatari-devel] Suppressing repeated log and trace output |
[ Thread Index |
Date Index
| More lists.tuxfamily.org/hatari-devel Archives
]
Hi,
on suggestion from Uwe, I've extended this code to cover also log
messages in addition to trace output.
Patches attached. Any comments?
(see limitations below.)
- Eero
On 28.8.2022 23.49, Eero Tamminen wrote:
I've had a problem with tracing that some programs hit specific trace
point constantly, either as result of bug, or as their normal working,
which can scroll the relevant (other) output from console view and
scroll buffer near-instantly.
Attached are patches to change tracing so that one can specify whether
trace output will compress repeated lines, and how many successive
repeats there needs to be for it to output intermediate info about the
repeats.
I'm mapping also LOG_TRACE_PRINT() macro to this, but there are few
traces where this falls down:
- IDE ATAPI CMD
- NF_SCSIDRV inout
Because they do multiple lines of output.
Then there are few things that access TraceFile directly for multi-line
output (instead of using LOG_TRACE_PRINT macro):
- CPU + DSP disasm tracing
- CPU + DSP register tracing
- AES tracing
I.e. one should not enable trace compression when tracing one of above 7
items is enabled.
Comments / thoughts?
From 5eee7ad7c862e9c8c23df812cd5bacceb189fd9b Mon Sep 17 00:00:00 2001
From: Eero Tamminen <oak@xxxxxxxxxxxxxx>
Date: Sat, 29 Oct 2022 00:42:12 +0300
Subject: [PATCH 4/4] Document "--repeat-limit" option
---
doc/hatari.1 | 4 ++++
doc/manual.html | 3 +++
doc/release-notes.txt | 1 +
3 files changed, 8 insertions(+)
diff --git a/doc/hatari.1 b/doc/hatari.1
index 7361568e..c59cd4a4 100644
--- a/doc/hatari.1
+++ b/doc/hatari.1
@@ -618,6 +618,10 @@ for available (comma separated) tracing flags
.B \-\-trace\-file <file>
Save trace output to <file> (default=stderr)
.TP
+.B \-\-repeat\-limit <x>
+Set repeat suppression limit (>1 = enable suppression) for log and
+trace messages
+.TP
.B \-\-parse <file>
Parse/execute debugger commands from <file>
.TP
diff --git a/doc/manual.html b/doc/manual.html
index 692cd07e..f5621f8a 100644
--- a/doc/manual.html
+++ b/doc/manual.html
@@ -1106,6 +1106,9 @@ E.g. EmuTOS uses it for debug output.</p>
<file></p>
<p class="paramdesc">Save trace output to <file>
(default=stderr)</p>
+<p class="parameter">--repeat-limit <x></p>
+<p class="paramdesc">Set repeat suppression limit
+(>1 = enable suppression) for log and trace message</p>
<p class="parameter">--parse
<file></p>
<p class="paramdesc">Parse/execute debugger commands from
diff --git a/doc/release-notes.txt b/doc/release-notes.txt
index 6e9b214f..79c74630 100644
--- a/doc/release-notes.txt
+++ b/doc/release-notes.txt
@@ -34,6 +34,7 @@ Emulator improvements:
- Debugger:
- Fix: free all debugger allocations before exit
- Fix: invalid free on freeing loaded GNU debug symbols
+ - Add "--repeat-limit" option to suppress repeated log & trace messages
- Preliminary support for disassembly output options working also for
CPU core disassembler in addition to external disassember output
- When entering debugger with 'history' enabled, disassembly address
--
2.30.2
From 7640682fa9c92a17e383a157a27d730f57c5f9ee Mon Sep 17 00:00:00 2001
From: Eero Tamminen <oak@xxxxxxxxxxxxxx>
Date: Sat, 29 Oct 2022 00:32:51 +0300
Subject: [PATCH 3/4] Support repeat suppression also for log messages
---
src/debug/debugui.c | 4 +-
src/debug/log.c | 274 ++++++++++++++++++++++++++------------------
src/debug/log.h | 4 +-
src/options.c | 10 +-
4 files changed, 169 insertions(+), 123 deletions(-)
diff --git a/src/debug/debugui.c b/src/debug/debugui.c
index 2051dbaf..871a3e45 100644
--- a/src/debug/debugui.c
+++ b/src/debug/debugui.c
@@ -1074,7 +1074,7 @@ void DebugUI_Init(void)
const dbgcommand_t *cpucmd, *dspcmd;
int cpucmds, dspcmds;
- Log_ResetTraceRepeats();
+ Log_ResetMsgRepeats();
/* already initialized? */
if (debugCommands)
@@ -1122,7 +1122,7 @@ void DebugUI_UnInit(void)
{
Profile_CpuFree();
Profile_DspFree();
- Log_ResetTraceRepeats();
+ Log_ResetMsgRepeats();
free(debugCommand);
debugCommands = 0;
}
diff --git a/src/debug/log.c b/src/debug/log.c
index fd1e344d..518f758b 100644
--- a/src/debug/log.c
+++ b/src/debug/log.c
@@ -31,6 +31,7 @@ const char Log_fileid[] = "Hatari log.c";
#include "file.h"
#include "vdi.h"
#include "options.h"
+#include "str.h"
int ExceptionDebugMask;
@@ -166,14 +167,22 @@ static flagname_t TraceFlags[] = {
uint64_t LogTraceFlags = TRACE_NONE;
FILE *TraceFile = NULL;
-/* trace line repeat compression limit, current repeat count,
- * and previous line content for checking repetition
+
+/* SDL GUI Alerts can show 4*50 chars at max, and much longer
+ * console messages are not very readable either, just slow
+ */
+#define MAX_MSG_LEN 256
+
+/* FILE* for output stream, message line repeat suppression limit,
+ * current repeat count, and previous line content for checking
+ * repetition
*/
static struct {
+ FILE *fp;
int limit;
int count;
- char prev[256];
-} TraceState;
+ char prev[MAX_MSG_LEN];
+} MsgState;
static FILE *hLogFile = NULL;
@@ -240,18 +249,116 @@ void Log_UnInit(void)
TraceFile = File_Close(TraceFile);
}
+/*-----------------------------------------------------------------------
+ * log/trace message repeat suppression handling
+ */
+
+static void printMsgRepeat(FILE *fp)
+{
+ /* strings already include trailing newline */
+ fprintf(fp, "%d repeats of: %s", MsgState.count, MsgState.prev);
+}
+
+/**
+ * If there is a pending that has not been output yet, output it.
+ */
+static void printPendingMsgRepeat(FILE *fp)
+{
+ if (likely(MsgState.count == 0))
+ return;
+ if (MsgState.count > 1)
+ printMsgRepeat(fp);
+ else
+ fputs(MsgState.prev, fp);
+}
+
+/**
+ * Output pending and given messages when appropriate and
+ * store given message if it's not a repeat.
+ */
+static void addMsgRepeat(FILE *fp, const char *line)
+{
+ /* repeated message? */
+ if (fp == MsgState.fp &&
+ unlikely(strcmp(line, MsgState.prev) == 0))
+ {
+ MsgState.count++;
+ /* repeat limit crossed? -> print once */
+ if (unlikely(MsgState.count >= MsgState.limit))
+ {
+ printMsgRepeat(fp);
+ MsgState.count = 0;
+ fflush(fp);
+ }
+ return;
+ }
+ /* no repeat -> print previous message/repeat */
+ printPendingMsgRepeat(MsgState.fp);
+
+ /* store + print new message */
+ Str_Copy(MsgState.prev, line, sizeof(MsgState.prev));
+ MsgState.count = 0;
+ MsgState.fp = fp;
+ fputs(line, fp);
+ fflush(fp);
+}
+
+/**
+ * Output pending message repeat info and reset repeat info.
+ */
+void Log_ResetMsgRepeats(void)
+{
+ printPendingMsgRepeat(MsgState.fp);
+ MsgState.prev[0] = '\0';
+ MsgState.count = 0;
+ MsgState.fp = NULL;
+}
+
+/**
+ * Enable message output repeat suppression, and set after
+ * how many repeats, repeat count & trace line are output.
+ * Return true for success.
+ */
+bool Log_SetMsgRepeatLimit(const char *value)
+{
+ int limit = atoi(value);
+ if (limit > 2)
+ {
+ fprintf(stderr, "Message repeat suppression enabled (limit = %d)\n", limit);
+ MsgState.limit = limit;
+ }
+ else
+ {
+ fprintf(stderr, "Message repeat suppression disabled (limit < 2)\n");
+ MsgState.limit = 0;
+ }
+ return true;
+}
/*-----------------------------------------------------------------------*/
/**
- * Print log prefix when needed
+ * Add log prefix to given string and return its lenght
*/
-static void Log_PrintPrefix(FILE *fp, LOGTYPE idx)
+static int Log_AddPrefix(char *msg, int len, LOGTYPE idx)
{
static const char* prefix[] = LOG_NAMES;
assert(idx >= 0 && idx < ARRAY_SIZE(prefix));
- if (prefix[idx])
- fprintf(fp, "%s: ", prefix[idx]);
+ return snprintf(msg, len, "%s: ", prefix[idx]);
+}
+
+/**
+ * Add a new-line if it's missing. 'msg' points to place
+ * where it should be, and size is buffer size.
+ */
+static void addMissingNewline(char *msg, int size)
+{
+ assert(size > 2);
+ if (size > 2 && msg[0] != '\n')
+ {
+ msg[1] = '\n';
+ msg[2] = '\0';
+ }
}
@@ -261,18 +368,29 @@ static void Log_PrintPrefix(FILE *fp, LOGTYPE idx)
*/
void Log_Printf(LOGTYPE nType, const char *psFormat, ...)
{
+ if (!(hLogFile && nType <= TextLogLevel))
+ return;
+
+ char line[sizeof(MsgState.prev)];
+ int count, len = sizeof(line);
+ char *msg = line;
+
+ count = Log_AddPrefix(line, len, nType);
+ msg += count;
+ len -= count;
+
va_list argptr;
+ va_start(argptr, psFormat);
+ count = vsnprintf(msg, len, psFormat, argptr);
+ va_end(argptr);
+ msg += count;
+ len -= count;
- if (hLogFile && nType <= TextLogLevel)
- {
- Log_PrintPrefix(hLogFile, nType);
- va_start(argptr, psFormat);
- vfprintf(hLogFile, psFormat, argptr);
- va_end(argptr);
- /* Add a new-line if necessary: */
- if (psFormat[strlen(psFormat)-1] != '\n')
- fputs("\n", hLogFile);
- }
+ addMissingNewline(msg-1, len+1);
+ if (MsgState.limit)
+ addMsgRepeat(hLogFile, line);
+ else
+ fputs(line, hLogFile);
}
@@ -287,30 +405,35 @@ void Log_AlertDlg(LOGTYPE nType, const char *psFormat, ...)
/* Output to log file: */
if (hLogFile && nType <= TextLogLevel)
{
- Log_PrintPrefix(hLogFile, nType);
+ char line[sizeof(MsgState.prev)];
+ int count, len = sizeof(line);
+ char *msg = line;
+
+ count = Log_AddPrefix(line, len, nType);
+ msg += count;
+ len -= count;
+
va_start(argptr, psFormat);
- vfprintf(hLogFile, psFormat, argptr);
+ count = vsnprintf(msg, len, psFormat, argptr);
va_end(argptr);
- /* Add a new-line if necessary: */
- if (psFormat[strlen(psFormat)-1] != '\n')
- fputs("\n", hLogFile);
+ msg += count;
+ len -= count;
+
+ addMissingNewline(msg-1, len+1);
+ if (MsgState.limit)
+ addMsgRepeat(hLogFile, line);
+ else
+ fputs(line, hLogFile);
}
/* Show alert dialog box: */
if (sdlscrn && nType <= AlertDlgLogLevel)
{
- char *psTmpBuf;
- psTmpBuf = malloc(2048);
- if (!psTmpBuf)
- {
- perror("Log_AlertDlg");
- return;
- }
+ char buf[MAX_MSG_LEN];
va_start(argptr, psFormat);
- vsnprintf(psTmpBuf, 2048, psFormat, argptr);
+ vsnprintf(buf, sizeof(buf), psFormat, argptr);
va_end(argptr);
- DlgAlert_Notice(psTmpBuf);
- free(psTmpBuf);
+ DlgAlert_Notice(buf);
}
}
@@ -514,70 +637,17 @@ char *Log_MatchTrace(const char *text, int state)
}
/**
- * Enable trace output compression and set after how many repeats,
- * repeat count & trace line are always output.
- * Return true for success.
- */
-bool Log_SetTraceRepeatLimit(const char *value)
-{
- int limit = atoi(value);
- if (limit > 2)
- {
- fprintf(stderr, "Trace line repeat compression enabled (limit = %d)\n", limit);
- TraceState.limit = limit;
- }
- else
- {
- fprintf(stderr, "Trace line repeat compression disabled (limit < 2)\n");
- TraceState.limit = 0;
- }
- return true;
-}
-
-static void printTraceRepeats(void)
-{
- /* trace output strings include trailing newline */
- fprintf(TraceFile, "%d repetitions of: %s",
- TraceState.count, TraceState.prev);
-}
-
-/**
- * If there are pending repeats that have not been output yet,
- * output them.
- */
-static void printPendingTraceRepeats(void)
-{
- if (likely(TraceState.count == 0))
- return;
- if (TraceState.count > 1)
- printTraceRepeats();
- else
- fputs(TraceState.prev, TraceFile);
-}
-
-/**
- * Output pending trace repeat info and reset repeat info.
- */
-void Log_ResetTraceRepeats(void)
-{
- if (TraceFile)
- printPendingTraceRepeats();
- TraceState.prev[0] = '\0';
- TraceState.count = 0;
-}
-
-/**
- * Do trace output with optional repeat compression
+ * Do trace output with optional repeat suppression
*/
void Log_Trace(const char *format, ...)
{
va_list argptr;
- char line[sizeof(TraceState.prev)];
+ char line[sizeof(MsgState.prev)];
if (!TraceFile)
return;
- if (!TraceState.limit)
+ if (!MsgState.limit)
{
va_start(argptr, format);
vfprintf(TraceFile, format, argptr);
@@ -589,22 +659,7 @@ void Log_Trace(const char *format, ...)
vsnprintf(line, sizeof(line), format, argptr);
va_end(argptr);
- if (unlikely(strcmp(line, TraceState.prev) == 0))
- {
- TraceState.count++;
- if (unlikely(TraceState.count >= TraceState.limit))
- {
- printTraceRepeats();
- TraceState.count = 0;
- fflush(TraceFile);
- }
- return;
- }
- strcpy(TraceState.prev, line);
- printPendingTraceRepeats();
- fputs(line, TraceFile);
- TraceState.count = 0;
- fflush(TraceFile);
+ addMsgRepeat(TraceFile, line);
}
#else /* !ENABLE_TRACING */
@@ -621,15 +676,6 @@ char *Log_MatchTrace(const char *text, int state)
return NULL;
}
-/** dummy */
-bool Log_SetTraceRepeatLimit(const char *value)
-{
- return false;
-}
-
-/** dummy */
-void Log_ResetTraceRepeats(void) {}
-
/** dummy */
void Log_Trace(const char *format, ...) {}
diff --git a/src/debug/log.h b/src/debug/log.h
index f90daf20..9275ecfb 100644
--- a/src/debug/log.h
+++ b/src/debug/log.h
@@ -82,8 +82,8 @@ extern void Log_AlertDlg(LOGTYPE nType, const char *psFormat, ...)
extern LOGTYPE Log_ParseOptions(const char *OptionStr);
extern const char* Log_SetTraceOptions(const char *OptionsStr);
extern char *Log_MatchTrace(const char *text, int state);
-extern bool Log_SetTraceRepeatLimit(const char *value);
-extern void Log_ResetTraceRepeats(void);
+extern bool Log_SetMsgRepeatLimit(const char *value);
+extern void Log_ResetMsgRepeats(void);
extern void Log_Trace(const char *format, ...)
__attribute__ ((format (printf, 1, 2)));
diff --git a/src/options.c b/src/options.c
index a7d370b8..8597f235 100644
--- a/src/options.c
+++ b/src/options.c
@@ -195,7 +195,7 @@ enum {
OPT_NATFEATS,
OPT_TRACE,
OPT_TRACEFILE,
- OPT_TRACE_REPEAT,
+ OPT_MSG_REPEAT,
OPT_PARSE,
OPT_SAVECONFIG,
OPT_CONTROLSOCKET,
@@ -489,8 +489,8 @@ static const opt_t HatariOptions[] = {
"<flags>", "Activate emulation tracing, see '--trace help'" },
{ OPT_TRACEFILE, NULL, "--trace-file",
"<file>", "Save trace output to <file> (default=stderr)" },
- { OPT_TRACE_REPEAT, NULL, "--repeat-limit",
- "<x>", "Set trace line repeat compression limit (>1 = enable compression)" },
+ { OPT_MSG_REPEAT, NULL, "--repeat-limit",
+ "<x>", "Set message repeat suppression limit (>1 = enable suppression)" },
{ OPT_PARSE, NULL, "--parse",
"<file>", "Parse/execute debugger commands from <file>" },
{ OPT_SAVECONFIG, NULL, "--saveconfig",
@@ -2185,9 +2185,9 @@ bool Opt_ParseParameters(int argc, const char * const argv[])
NULL);
break;
- case OPT_TRACE_REPEAT:
+ case OPT_MSG_REPEAT:
i += 1;
- ok = Log_SetTraceRepeatLimit(argv[i]);
+ ok = Log_SetMsgRepeatLimit(argv[i]);
break;
case OPT_CONTROLSOCKET:
--
2.30.2
From 590ce2303962501d95f8e04d88125614585dbdae Mon Sep 17 00:00:00 2001
From: Eero Tamminen <oak@xxxxxxxxxxxxxx>
Date: Sun, 28 Aug 2022 22:11:48 +0300
Subject: [PATCH 2/4] Change CPU+DSP symbol tracing to use Log_Trace() function
So that repeated entries will be compressed on output.
---
src/debug/debugcpu.c | 29 ++++++++++-------------------
src/debug/debugdsp.c | 31 +++++++++++--------------------
2 files changed, 21 insertions(+), 39 deletions(-)
diff --git a/src/debug/debugcpu.c b/src/debug/debugcpu.c
index 0ab0daeb..d4829b68 100644
--- a/src/debug/debugcpu.c
+++ b/src/debug/debugcpu.c
@@ -143,23 +143,6 @@ static int DebugCpu_SaveBin(int nArgc, char *psArgs[])
}
-/**
- * Check whether given address matches any CPU symbol and whether
- * there's profiling information available for it. If yes, show it.
- *
- * @return true if symbol was shown, false otherwise
- */
-static bool DebugCpu_ShowAddressInfo(uint32_t addr, FILE *fp)
-{
- const char *symbol = Symbols_GetByCpuAddress(addr, SYMTYPE_ALL);
- if (symbol)
- {
- fprintf(fp, "%s:\n", symbol);
- return true;
- }
- return false;
-}
-
/**
* Disassemble - arg = starting address, or PC.
*/
@@ -202,6 +185,7 @@ int DebugCpu_DisAsm(int nArgc, char *psArgs[])
prev_addr = disasm_addr;
for (shown = 0; shown < lines && disasm_addr < disasm_upper; shown++)
{
+ const char *symbol;
if (prev_addr < pc && disasm_addr > pc)
{
fputs("ERROR, disassembly misaligned with PC address, correcting\n", debugOutput);
@@ -214,8 +198,12 @@ int DebugCpu_DisAsm(int nArgc, char *psArgs[])
shown++;
}
prev_addr = disasm_addr;
- if (DebugCpu_ShowAddressInfo(disasm_addr, debugOutput))
+ symbol = Symbols_GetByCpuAddress(disasm_addr, SYMTYPE_ALL);
+ if (symbol)
+ {
+ fprintf(debugOutput, "%s:\n", symbol);
shown++;
+ }
Disasm(debugOutput, (uaecptr)disasm_addr, &nextpc, 1);
disasm_addr = nextpc;
}
@@ -900,7 +888,10 @@ void DebugCpu_Check(void)
}
if (LOG_TRACE_LEVEL((TRACE_CPU_DISASM|TRACE_CPU_SYMBOLS)))
{
- DebugCpu_ShowAddressInfo(M68000_GetPC(), TraceFile);
+ const char *symbol;
+ symbol = Symbols_GetByCpuAddress(M68000_GetPC(), SYMTYPE_ALL);
+ if (symbol)
+ Log_Trace("%s\n", symbol);
}
if (LOG_TRACE_LEVEL(TRACE_CPU_REGS))
{
diff --git a/src/debug/debugdsp.c b/src/debug/debugdsp.c
index 5a978f17..6e8ea872 100644
--- a/src/debug/debugdsp.c
+++ b/src/debug/debugdsp.c
@@ -101,24 +101,6 @@ error_msg:
}
-/**
- * Check whether given address matches any DSP symbol and whether
- * there's profiling information available for it. If yes, show it.
- *
- * @return true if symbol was shown, false otherwise
- */
-static bool DebugDsp_ShowAddressInfo(uint16_t addr, FILE *fp)
-{
- const char *symbol = Symbols_GetByDspAddress(addr, SYMTYPE_ALL);
- if (symbol)
- {
- fprintf(fp, "%s:\n", symbol);
- return true;
- }
- return false;
-}
-
-
/**
* DSP disassemble - arg = starting address/range, or PC.
*/
@@ -176,6 +158,8 @@ int DebugDsp_DisAsm(int nArgc, char *psArgs[])
prev_addr = dsp_disasm_addr;
fprintf(debugOutput, "DSP disasm 0x%hx-0x%hx:\n", dsp_disasm_addr, dsp_disasm_upper);
for (shown = 1; shown < lines && dsp_disasm_addr < dsp_disasm_upper; shown++) {
+ const char *symbol;
+
if (prev_addr < pc && dsp_disasm_addr > pc)
{
fputs("ERROR, disassembly misaligned with PC address, correcting\n", debugOutput);
@@ -188,8 +172,12 @@ int DebugDsp_DisAsm(int nArgc, char *psArgs[])
shown++;
}
prev_addr = dsp_disasm_addr;
- if (DebugDsp_ShowAddressInfo(dsp_disasm_addr, debugOutput))
+ symbol = Symbols_GetByDspAddress(dsp_disasm_addr, SYMTYPE_ALL);
+ if (symbol)
+ {
+ fprintf(debugOutput, "%s:\n", symbol);
shown++;
+ }
dsp_disasm_addr = DSP_DisasmAddress(debugOutput, dsp_disasm_addr, dsp_disasm_addr);
}
fflush(debugOutput);
@@ -529,7 +517,10 @@ void DebugDsp_Check(void)
}
if (LOG_TRACE_LEVEL((TRACE_DSP_DISASM|TRACE_DSP_SYMBOLS)))
{
- DebugDsp_ShowAddressInfo(DSP_GetPC(), TraceFile);
+ const char *symbol;
+ symbol = Symbols_GetByDspAddress(DSP_GetPC(), SYMTYPE_ALL);
+ if (symbol)
+ Log_Trace("%s\n", symbol);
}
if (nDspActiveCBs)
{
--
2.30.2
From 13643d54603a5c68c46aeeea0f5335048ed2a96d Mon Sep 17 00:00:00 2001
From: Eero Tamminen <oak@xxxxxxxxxxxxxx>
Date: Sun, 28 Aug 2022 20:54:01 +0300
Subject: [PATCH 1/4] Support for suppressing successive identical trace
messages
There are situations (bugs) where specific tracepoint starts repeating
constantly. After it repeats for a while, rest is useless, fills logs
quickly and often scrolls the useful info (about how that sitation was
entered) out of view faster than one can react.
Repeat checking may slow tracing measurably, so it can be enabled only
at runtime with the new "--repeat-limit" option.
If it is needed, high value in thousands is recommended.
---
src/debug/debugui.c | 3 +
src/debug/log.c | 117 +++++++++++++++++++++++++++++++++-
src/debug/log.h | 8 ++-
src/main.c | 2 +-
src/options.c | 8 +++
tests/debugger/test-dummies.c | 1 +
6 files changed, 135 insertions(+), 4 deletions(-)
diff --git a/src/debug/debugui.c b/src/debug/debugui.c
index 52bf1629..2051dbaf 100644
--- a/src/debug/debugui.c
+++ b/src/debug/debugui.c
@@ -1074,6 +1074,8 @@ void DebugUI_Init(void)
const dbgcommand_t *cpucmd, *dspcmd;
int cpucmds, dspcmds;
+ Log_ResetTraceRepeats();
+
/* already initialized? */
if (debugCommands)
return;
@@ -1120,6 +1122,7 @@ void DebugUI_UnInit(void)
{
Profile_CpuFree();
Profile_DspFree();
+ Log_ResetTraceRepeats();
free(debugCommand);
debugCommands = 0;
}
diff --git a/src/debug/log.c b/src/debug/log.c
index 62307b46..fd1e344d 100644
--- a/src/debug/log.c
+++ b/src/debug/log.c
@@ -166,6 +166,15 @@ static flagname_t TraceFlags[] = {
uint64_t LogTraceFlags = TRACE_NONE;
FILE *TraceFile = NULL;
+/* trace line repeat compression limit, current repeat count,
+ * and previous line content for checking repetition
+ */
+static struct {
+ int limit;
+ int count;
+ char prev[256];
+} TraceState;
+
static FILE *hLogFile = NULL;
/* local settings, to be able change them temporarily */
@@ -204,7 +213,7 @@ int Log_Init(void)
hLogFile = File_Open(ConfigureParams.Log.sLogFileName, "w");
TraceFile = File_Open(ConfigureParams.Log.sTraceFileName, "w");
-
+
return (hLogFile && TraceFile);
}
@@ -504,6 +513,100 @@ char *Log_MatchTrace(const char *text, int state)
return NULL;
}
+/**
+ * Enable trace output compression and set after how many repeats,
+ * repeat count & trace line are always output.
+ * Return true for success.
+ */
+bool Log_SetTraceRepeatLimit(const char *value)
+{
+ int limit = atoi(value);
+ if (limit > 2)
+ {
+ fprintf(stderr, "Trace line repeat compression enabled (limit = %d)\n", limit);
+ TraceState.limit = limit;
+ }
+ else
+ {
+ fprintf(stderr, "Trace line repeat compression disabled (limit < 2)\n");
+ TraceState.limit = 0;
+ }
+ return true;
+}
+
+static void printTraceRepeats(void)
+{
+ /* trace output strings include trailing newline */
+ fprintf(TraceFile, "%d repetitions of: %s",
+ TraceState.count, TraceState.prev);
+}
+
+/**
+ * If there are pending repeats that have not been output yet,
+ * output them.
+ */
+static void printPendingTraceRepeats(void)
+{
+ if (likely(TraceState.count == 0))
+ return;
+ if (TraceState.count > 1)
+ printTraceRepeats();
+ else
+ fputs(TraceState.prev, TraceFile);
+}
+
+/**
+ * Output pending trace repeat info and reset repeat info.
+ */
+void Log_ResetTraceRepeats(void)
+{
+ if (TraceFile)
+ printPendingTraceRepeats();
+ TraceState.prev[0] = '\0';
+ TraceState.count = 0;
+}
+
+/**
+ * Do trace output with optional repeat compression
+ */
+void Log_Trace(const char *format, ...)
+{
+ va_list argptr;
+ char line[sizeof(TraceState.prev)];
+
+ if (!TraceFile)
+ return;
+
+ if (!TraceState.limit)
+ {
+ va_start(argptr, format);
+ vfprintf(TraceFile, format, argptr);
+ va_end(argptr);
+ fflush(TraceFile);
+ return;
+ }
+ va_start(argptr, format);
+ vsnprintf(line, sizeof(line), format, argptr);
+ va_end(argptr);
+
+ if (unlikely(strcmp(line, TraceState.prev) == 0))
+ {
+ TraceState.count++;
+ if (unlikely(TraceState.count >= TraceState.limit))
+ {
+ printTraceRepeats();
+ TraceState.count = 0;
+ fflush(TraceFile);
+ }
+ return;
+ }
+ strcpy(TraceState.prev, line);
+ printPendingTraceRepeats();
+ fputs(line, TraceFile);
+ TraceState.count = 0;
+ fflush(TraceFile);
+}
+
#else /* !ENABLE_TRACING */
/** dummy */
@@ -518,4 +621,16 @@ char *Log_MatchTrace(const char *text, int state)
return NULL;
}
+/** dummy */
+bool Log_SetTraceRepeatLimit(const char *value)
+{
+ return false;
+}
+
+/** dummy */
+void Log_ResetTraceRepeats(void) {}
+
+/** dummy */
+void Log_Trace(const char *format, ...) {}
+
#endif /* !ENABLE_TRACING */
diff --git a/src/debug/log.h b/src/debug/log.h
index ce6b415e..f90daf20 100644
--- a/src/debug/log.h
+++ b/src/debug/log.h
@@ -82,6 +82,10 @@ extern void Log_AlertDlg(LOGTYPE nType, const char *psFormat, ...)
extern LOGTYPE Log_ParseOptions(const char *OptionStr);
extern const char* Log_SetTraceOptions(const char *OptionsStr);
extern char *Log_MatchTrace(const char *text, int state);
+extern bool Log_SetTraceRepeatLimit(const char *value);
+extern void Log_ResetTraceRepeats(void);
+extern void Log_Trace(const char *format, ...)
+ __attribute__ ((format (printf, 1, 2)));
#ifndef __GNUC__
#undef __attribute__
@@ -299,7 +303,7 @@ extern uint64_t LogTraceFlags;
#if ENABLE_TRACING
#define LOG_TRACE(level, ...) \
- if (unlikely(LogTraceFlags & (level))) { fprintf(TraceFile, __VA_ARGS__); fflush(TraceFile); }
+ if (unlikely(LogTraceFlags & (level))) { Log_Trace(__VA_ARGS__); }
#define LOG_TRACE_LEVEL( level ) (unlikely(LogTraceFlags & (level)))
@@ -315,7 +319,7 @@ extern uint64_t LogTraceFlags;
* In code it's used in such a way that it will be optimized away when tracing
* is disabled.
*/
-#define LOG_TRACE_PRINT(...) fprintf(TraceFile , __VA_ARGS__)
+#define LOG_TRACE_PRINT(...) Log_Trace(__VA_ARGS__)
#endif /* HATARI_LOG_H */
diff --git a/src/main.c b/src/main.c
index 4371f64f..8df85467 100644
--- a/src/main.c
+++ b/src/main.c
@@ -823,10 +823,10 @@ static void Main_UnInit(void)
SDL_Quit();
/* Close debug log file */
+ DebugUI_UnInit();
Log_UnInit();
Paths_UnInit();
- DebugUI_UnInit();
}
diff --git a/src/options.c b/src/options.c
index ba462072..a7d370b8 100644
--- a/src/options.c
+++ b/src/options.c
@@ -195,6 +195,7 @@ enum {
OPT_NATFEATS,
OPT_TRACE,
OPT_TRACEFILE,
+ OPT_TRACE_REPEAT,
OPT_PARSE,
OPT_SAVECONFIG,
OPT_CONTROLSOCKET,
@@ -488,6 +489,8 @@ static const opt_t HatariOptions[] = {
"<flags>", "Activate emulation tracing, see '--trace help'" },
{ OPT_TRACEFILE, NULL, "--trace-file",
"<file>", "Save trace output to <file> (default=stderr)" },
+ { OPT_TRACE_REPEAT, NULL, "--repeat-limit",
+ "<x>", "Set trace line repeat compression limit (>1 = enable compression)" },
{ OPT_PARSE, NULL, "--parse",
"<file>", "Parse/execute debugger commands from <file>" },
{ OPT_SAVECONFIG, NULL, "--saveconfig",
@@ -2182,6 +2185,11 @@ bool Opt_ParseParameters(int argc, const char * const argv[])
NULL);
break;
+ case OPT_TRACE_REPEAT:
+ i += 1;
+ ok = Log_SetTraceRepeatLimit(argv[i]);
+ break;
+
case OPT_CONTROLSOCKET:
i += 1;
errstr = Control_SetSocket(argv[i]);
diff --git a/tests/debugger/test-dummies.c b/tests/debugger/test-dummies.c
index 59926732..17684ab2 100644
--- a/tests/debugger/test-dummies.c
+++ b/tests/debugger/test-dummies.c
@@ -8,6 +8,7 @@
uint64_t LogTraceFlags = 0;
FILE *TraceFile;
+void Log_Trace(const char *format, ...) { }
/* fake Hatari configuration variables for number parsing */
#include "configuration.h"
--
2.30.2