Re: [PATCH 5/5] perf intel-pt: Support itrace option flag d+e to log on error

From: Andi Kleen
Date: Thu Sep 01 2022 - 10:32:08 EST



On 9/1/2022 4:00 AM, Adrian Hunter wrote:
Pass d+e option and log size via intel_pt_log_enable(). Allocate a buffer
for log messages and provide intel_pt_log_dump_buf() to dump and reset the
buffer upon decoder errors.

Example:

$ sudo perf record -e intel_pt// sleep 1
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.094 MB perf.data ]
$ sudo perf config itrace.debug-log-buffer-size=300
$ sudo perf script --itrace=ed+e+o | head -20
Dumping debug log buffer (first line may be sliced)
Other
ffffffff96ca22f6: 48 89 e5 Other
ffffffff96ca22f9: 65 48 8b 05 ff e0 38 69 Other
ffffffff96ca2301: 48 3d c0 a5 c1 98 Other
ffffffff96ca2307: 74 08 Jcc +8
ffffffff96ca2311: 5d Other
ffffffff96ca2312: c3 Ret
ERROR: Bad RET compression (TNT=N) at 0xffffffff96ca2312
End of debug log buffer dump
instruction trace error type 1 time 15913.537143482 cpu 5 pid 36292 tid 36292 ip 0xffffffff96ca2312 code 6: Trace doesn't match instruction
Dumping debug log buffer (first line may be sliced)
Other
ffffffff96ce7fe9: f6 47 2e 20 Other
ffffffff96ce7fed: 74 11 Jcc +17
ffffffff96ce7fef: 48 8b 87 28 0a 00 00 Other
ffffffff96ce7ff6: 5d Other
ffffffff96ce7ff7: 48 8b 40 18 Other
ffffffff96ce7ffb: c3 Ret
ERROR: Bad RET compression (TNT=N) at 0xffffffff96ce7ffb
Warning:
8 instruction trace errors

Signed-off-by: Adrian Hunter <adrian.hunter@xxxxxxxxx>
---
tools/perf/Documentation/perf-intel-pt.txt | 5 +-
.../perf/util/intel-pt-decoder/intel-pt-log.c | 94 ++++++++++++++++++-
.../perf/util/intel-pt-decoder/intel-pt-log.h | 3 +-
tools/perf/util/intel-pt.c | 20 +++-
4 files changed, 117 insertions(+), 5 deletions(-)

diff --git a/tools/perf/Documentation/perf-intel-pt.txt b/tools/perf/Documentation/perf-intel-pt.txt
index d5ddb968bcf4..92464a5d7eaf 100644
--- a/tools/perf/Documentation/perf-intel-pt.txt
+++ b/tools/perf/Documentation/perf-intel-pt.txt
@@ -989,10 +989,13 @@ must be preceded by either '+' or '-'. The flags support by Intel PT are:
-a Suppress logging of perf events
+a Log all perf events
+ +e Output only on decoding errors (size configurable)
+o Output to stdout instead of "intel_pt.log"
By default, logged perf events are filtered by any specified time ranges, but
-flag +a overrides that.
+flag +a overrides that. The +e flag can be useful for analyzing errors. By
+default, the log size in that case is 16384 bytes, but can be altered by
+linkperf:perf-config[1] e.g. perf config itrace.debug-log-buffer-size=30000
In addition, the period of the "instructions" event can be specified. e.g.
diff --git a/tools/perf/util/intel-pt-decoder/intel-pt-log.c b/tools/perf/util/intel-pt-decoder/intel-pt-log.c
index 5f5dfc8753f3..ea96dcae187a 100644
--- a/tools/perf/util/intel-pt-decoder/intel-pt-log.c
+++ b/tools/perf/util/intel-pt-decoder/intel-pt-log.c
@@ -5,12 +5,16 @@
*/
#include <stdio.h>
+#include <stdlib.h>
#include <stdint.h>
#include <inttypes.h>
#include <stdarg.h>
#include <stdbool.h>
#include <string.h>
+#include <linux/zalloc.h>
+#include <linux/kernel.h>
+
#include "intel-pt-log.h"
#include "intel-pt-insn-decoder.h"
@@ -21,15 +25,20 @@
static FILE *f;
static char log_name[MAX_LOG_NAME];
bool intel_pt_enable_logging;
+static bool intel_pt_dump_log_on_error;
+static unsigned int intel_pt_log_on_error_size;
+static struct log_buf log_buf;
void *intel_pt_log_fp(void)
{
return f;
}
-void intel_pt_log_enable(void)
+void intel_pt_log_enable(bool dump_log_on_error, unsigned int log_on_error_size)
{
intel_pt_enable_logging = true;
+ intel_pt_dump_log_on_error = dump_log_on_error;
+ intel_pt_log_on_error_size = log_on_error_size;
}
void intel_pt_log_disable(void)
@@ -74,6 +83,87 @@ static void intel_pt_print_no_data(uint64_t pos, int indent)
fprintf(f, " ");
}
+#define DFLT_BUF_SZ (16 * 1024)
+
+struct log_buf {
+ char *buf;
+ size_t buf_sz;
+ size_t head;
+ bool wrapped;
+ FILE *backend;
+};
+
+static ssize_t log_buf__write(void *cookie, const char *buf, size_t size)
+{
+ struct log_buf *b = cookie;
+ size_t sz = size;
+
+ if (!b->buf)
+ return size;
+
+ while (sz) {
+ size_t space = b->buf_sz - b->head;
+ size_t n = min(space, sz);
+
+ memcpy(b->buf + b->head, buf, n);
+ sz -= n;
+ buf += n;
+ b->head += n;
+ if (sz && b->head >= b->buf_sz) {
+ b->head = 0;
+ b->wrapped = true;
+ }
+ }


I would add an assert or somesuch for the case where sz is larger than the buffer size, which would otherwise loop forever.


+
+static void log_buf__dump(struct log_buf *b)
+{
+ if (!b->buf)
+ return;
+
+ fflush(f);
+ fprintf(b->backend, "Dumping debug log buffer (first line may be sliced)\n");


Should be easy to skip the first line, no?


Rest looks good.

Reviewed-by: Andi Kleen <ak@xxxxxxxxxxxxxxx>


-Andi