[igt-dev] [i-g-t, v2, 01/11] tools/intel_guc_logger: Re-enable basic functionality
Dong, Zhanjun
zhanjun.dong at intel.com
Fri Jan 20 20:26:56 UTC 2023
See my comments inline below.
Regards,
Zhanjun Dong
On 2022-12-06 3:58 a.m., Alan Previn wrote:
> Fix these multiple issues to get basic functionality up
> and running on GuC using:
> 1. Start using the updated debugfs path for all GuC relay-logging
> file names.
> 2. Use the updated debugfs names for the relay-logging control
> and channel files to match kernel changes.
> 3. Start querrying the relay sub-buffer info (buffer size and
> number of sub-buffers) from kernel's new debugfs files.
> 4. Separate the control enabling from the log-level-setting and
> keep the control handle open while collecting the logs.
>
> Signed-off-by: Alan Previn <alan.previn.teres.alexis at intel.com>
> ---
> tools/intel_guc_logger.c | 179 ++++++++++++++++++++++++++++-----------
> 1 file changed, 129 insertions(+), 50 deletions(-)
>
> diff --git a/tools/intel_guc_logger.c b/tools/intel_guc_logger.c
> index 5f1de8db..4a991127 100644
> --- a/tools/intel_guc_logger.c
> +++ b/tools/intel_guc_logger.c
> @@ -42,24 +42,30 @@
>
> #include "igt.h"
>
> +#define KB(x) ((uint64_t)(x) * 1024)
> #define MB(x) ((uint64_t)(x) * 1024 * 1024)
> #ifndef PAGE_SIZE
> #define PAGE_SIZE 4096
> #endif
> -/* Currently the size of GuC log buffer is 19 pages & so is the size of relay
> - * subbuffer. If the size changes in future, then this define also needs to be
> - * updated accordingly.
> - */
> -#define SUBBUF_SIZE (19*PAGE_SIZE)
> -/* Need large buffering from logger side to hide the DISK IO latency, Driver
> - * can only store 8 snapshots of GuC log buffer in relay.
> - */
> -#define NUM_SUBBUFS 100
>
> -#define RELAY_FILE_NAME "guc_log"
> #define DEFAULT_OUTPUT_FILE_NAME "guc_log_dump.dat"
> -#define CONTROL_FILE_NAME "i915_guc_log_control"
>
> +#define GLR_LOGLEVEL_NAME "guc_log_level"
> +#define GLR_CTL_NAME "guc_log_relay_ctl"
> +#define GLR_CHANNEL_NAME "guc_log_relay_chan0"
> +
> +#define DEFAULT_SUBBUF_COUNT (4 * 8)
> + /* default to kernel built-in: *
> + * 4 x 8 subbuf regions *
> + */
> +#define DEFAULT_SUBBUF_SIZE (KB(4 + 8 + 64))
> + /* default to kernel built-ins : *
> + * 4K -> buffer states array *
> + * 8K -> GuC crash dump *
> + * 64K -> log events buffer *
> + */
> +
> +int drm_fd;
> char *read_buffer;
> char *out_filename;
> int poll_timeout = 2; /* by default 2ms timeout */
> @@ -68,23 +74,53 @@ pthread_t flush_thread;
> int verbosity_level = 3; /* by default capture logs at max verbosity */
> uint32_t produced, consumed;
> uint64_t total_bytes_written;
> -int num_buffers = NUM_SUBBUFS;
> -int relay_fd, outfile_fd = -1;
> +int subbuf_count;
> +int subbuf_size;
> +int ctl_fd, relay_fd, outfile_fd = -1;
> uint32_t test_duration, max_filesize;
> pthread_cond_t underflow_cond, overflow_cond;
> bool stop_logging, discard_oldlogs, capturing_stopped;
> +char *gucfspath;
>
> -static void guc_log_control(bool enable, uint32_t log_level)
> +static void get_guc_subbuf_info(void)
> +{
> + int fd, ret, j;
> + char *path;
> + const char *dbg_fs_names[2] = {"guc_log_relay_buf_size\0",
> + "guc_log_relay_subbuf_count\0"};
> + char outstr[128];
> + uint64_t tmp[2] = {DEFAULT_SUBBUF_SIZE, DEFAULT_SUBBUF_COUNT};
> +
> + for (j = 0; j < 2; j++) {
> + igt_assert_neq(asprintf(&path, "%s/%s", gucfspath, dbg_fs_names[j]), -1);
> + igt_info("Opening subbuf path %s\n", path);
> + fd = igt_debugfs_open(drm_fd, path, O_RDONLY);
> + free(path);
> + igt_assert_f(fd >= 0, "couldn't open the GuC log relay-subbuf file\n");
> + ret = read(fd, outstr, sizeof(outstr) - 1);
> + igt_assert(ret > 0);
> + outstr[ret] = '\0';
> + tmp[j] = atoll(outstr);
> + close(fd);
> + }
> + subbuf_size = tmp[0];
> + subbuf_count = tmp[1];
How about define tmp[x] the same data type as subbuf_xxx to avoid type
rang diff?
> + igt_info("Debugfs retrieved subbuf info: size=%d, count=%d\n",
> + subbuf_size, subbuf_count);
> +}
> +
> +static void guc_log_verbosity(bool enable, int log_level)
> {
> - int control_fd;
> - char data[19];
> + char *str;
> + int loglevelfd;
> uint64_t val;
> int ret;
>
> - igt_assert_lte(log_level, 3);
> -
> - control_fd = igt_debugfs_open(-1, CONTROL_FILE_NAME, O_WRONLY);
> - igt_assert_f(control_fd >= 0, "couldn't open the guc log control file\n");
> + igt_assert_neq(asprintf(&str, "%s/%s", gucfspath, GLR_LOGLEVEL_NAME), -1);
> + igt_info("Opening log level -> %s\n", str);
> + loglevelfd = igt_debugfs_open(drm_fd, str, O_WRONLY);
> + free(str);
> + igt_assert_f(loglevelfd >= 0, "couldn't open the GuC log level file\n");
>
> /*
> * i915 expects GuC log level to be specified as:
> @@ -96,13 +132,51 @@ static void guc_log_control(bool enable, uint32_t log_level)
> */
> val = enable ? log_level + 1 : 0;
>
> - ret = snprintf(data, sizeof(data), "0x%" PRIx64, val);
> - igt_assert(ret > 2 && ret < sizeof(data));
> + ret = asprintf(&str, "0x%" PRIx64, val);
> + igt_assert_neq(ret, -1);
> + ret = write(loglevelfd, str, ret);
> + free(str);
> + igt_assert_f(ret > 0, "couldn't write verbosity to log level file\n");
> + igt_info("Set GuC log level = %d\n", (int)val);
> +
> + close(loglevelfd);
> +}
>
> - ret = write(control_fd, data, ret);
> - igt_assert_f(ret > 0, "couldn't write to the log control file\n");
> +static void guc_log_control(bool enable, uint32_t log_level)
How about to have the same log_level type among the file?
> +{
> + char *str;
> + uint64_t val = 0;
> + int ret;
>
> - close(control_fd);
> + if (enable) {
> + igt_assert_neq(asprintf(&str, "%s/%s", gucfspath, GLR_CTL_NAME), -1);
> + igt_info("Opening control file -> %s\n", str);
> + ctl_fd = igt_debugfs_open(drm_fd, str, O_WRONLY);
> + free(str);
> + igt_assert_f(ctl_fd >= 0, "couldn't open the GuC log relay-ctl file\n");
> + val = 1;
> + }
> +
> + /*
> + * i915 expects relay logging controls:
> + * 1 : open + enable relay logging
> + * 2 : flush
> + * 0 : disable relay logging + close
> + */
> + if (ctl_fd) {
> + ret = asprintf(&str, "0x%" PRIx64, val);
val could only be 0 or 1 in this function now, no uint64 needed, it
could be something like:
str = val? "0x1" : "0x0";
No string alloc/free needed.
> + igt_assert_neq(ret, -1);
> + ret = write(ctl_fd, str, ret);
> + free(str);
> + igt_assert_f(ret > 0, "couldn't write to the log control file\n");
> + }
> +
> + guc_log_verbosity(enable, log_level);
> +
> + if (!enable) {
> + igt_info("Closing control file\n");
> + close(ctl_fd);
> + }
> }
>
> static void int_sig_handler(int sig)
> @@ -119,18 +193,18 @@ static void pull_leftover_data(void)
>
> do {
> /* Read the logs from relay buffer */
> - ret = read(relay_fd, read_buffer, SUBBUF_SIZE);
> + ret = read(relay_fd, read_buffer, subbuf_size);
> if (!ret)
> break;
>
> - igt_assert_f(ret > 0, "failed to read from the guc log file\n");
> - igt_assert_f(ret == SUBBUF_SIZE, "invalid read from relay file\n");
> + igt_assert_f(ret > 0, "failed to read from the GuC log file\n");
> + igt_assert_f(ret == subbuf_size, "invalid read from relay file\n");
>
> bytes_read += ret;
>
> if (outfile_fd >= 0) {
> - ret = write(outfile_fd, read_buffer, SUBBUF_SIZE);
> - igt_assert_f(ret == SUBBUF_SIZE, "couldn't dump the logs in a file\n");
> + ret = write(outfile_fd, read_buffer, subbuf_size);
> + igt_assert_f(ret == subbuf_size, "couldn't dump the logs in a file\n");
> total_bytes_written += ret;
> }
> } while(1);
> @@ -149,7 +223,7 @@ static void pull_data(void)
> int ret;
>
> pthread_mutex_lock(&mutex);
> - while (num_filled_bufs() >= num_buffers) {
> + while (num_filled_bufs() >= subbuf_count) {
> igt_debug("overflow, will wait, produced %u, consumed %u\n", produced, consumed);
> /* Stall the main thread in case of overflow, as there are no
> * buffers available to store the new logs, otherwise there
> @@ -159,12 +233,12 @@ static void pull_data(void)
> };
> pthread_mutex_unlock(&mutex);
>
> - ptr = read_buffer + (produced % num_buffers) * SUBBUF_SIZE;
> + ptr = read_buffer + (produced % subbuf_count) * subbuf_size;
>
> /* Read the logs from relay buffer */
> - ret = read(relay_fd, ptr, SUBBUF_SIZE);
> - igt_assert_f(ret >= 0, "failed to read from the guc log file\n");
> - igt_assert_f(!ret || ret == SUBBUF_SIZE, "invalid read from relay file\n");
> + ret = read(relay_fd, ptr, subbuf_size);
> + igt_assert_f(ret >= 0, "failed to read from the GuC log file\n");
> + igt_assert_f(!ret || ret == subbuf_size, "invalid read from relay file\n");
>
> if (ret) {
> pthread_mutex_lock(&mutex);
> @@ -204,10 +278,10 @@ static void *flusher(void *arg)
> };
> pthread_mutex_unlock(&mutex);
>
> - ptr = read_buffer + (consumed % num_buffers) * SUBBUF_SIZE;
> + ptr = read_buffer + (consumed % subbuf_count) * subbuf_size;
>
> - ret = write(outfile_fd, ptr, SUBBUF_SIZE);
> - igt_assert_f(ret == SUBBUF_SIZE, "couldn't dump the logs in a file\n");
> + ret = write(outfile_fd, ptr, subbuf_size);
> + igt_assert_f(ret == subbuf_size, "couldn't dump the logs in a file\n");
>
> total_bytes_written += ret;
> if (max_filesize && (total_bytes_written > MB(max_filesize))) {
> @@ -260,8 +334,13 @@ static void init_flusher_thread(void)
>
> static void open_relay_file(void)
> {
> - relay_fd = igt_debugfs_open(-1, RELAY_FILE_NAME, O_RDONLY);
> - igt_assert_f(relay_fd >= 0, "couldn't open the guc log file\n");
> + char *path;
> +
> + igt_assert_neq(asprintf(&path, "%s/%s", gucfspath, GLR_CHANNEL_NAME), -1);
> + igt_info("Opening this path -> %s\n", path);
> + relay_fd = igt_debugfs_open(drm_fd, path, O_RDONLY);
> + free(path);
> + igt_assert_f(relay_fd >= 0, "couldn't open the GuC log relay-channel file\n");
>
> /* Purge the old/boot-time logs from the relay buffer.
> * This is more for Val team's requirement, where they have to first
> @@ -292,7 +371,7 @@ static void open_output_file(void)
>
> static void init_main_thread(void)
> {
> - struct sched_param thread_sched;
> + struct sched_param thread_sched;
> int ret;
>
> /* Run the main thread at highest priority to ensure that it always
> @@ -311,11 +390,11 @@ static void init_main_thread(void)
> igt_assert_f(0, "SIGALRM handler registration failed\n");
>
> /* Need an aligned pointer for direct IO */
> - ret = posix_memalign((void **)&read_buffer, PAGE_SIZE, num_buffers * SUBBUF_SIZE);
> + ret = posix_memalign((void **)&read_buffer, PAGE_SIZE, subbuf_count * subbuf_size);
> igt_assert_f(ret == 0, "couldn't allocate the read buffer\n");
>
> /* Keep the pages locked in RAM, avoid page fault overhead */
> - ret = mlock(read_buffer, num_buffers * SUBBUF_SIZE);
> + ret = mlock(read_buffer, subbuf_count * subbuf_size);
> igt_assert_f(ret == 0, "failed to lock memory\n");
>
> /* Enable the logging, it may not have been enabled from boot and so
> @@ -342,11 +421,6 @@ static int parse_options(int opt, int opt_index, void *data)
> igt_assert_f(out_filename, "Couldn't allocate the o/p filename\n");
> igt_debug("logs to be stored in file %s\n", out_filename);
> break;
> - case 'b':
> - num_buffers = atoi(optarg);
> - igt_assert_f(num_buffers > 0, "invalid input for -b option\n");
> - igt_debug("number of buffers to be used is %d\n", num_buffers);
> - break;
> case 't':
> test_duration = atoi(optarg);
> igt_assert_f(test_duration > 0, "invalid input for -t option\n");
> @@ -377,7 +451,6 @@ static void process_command_line(int argc, char **argv)
> static struct option long_options[] = {
> {"verbosity", required_argument, 0, 'v'},
> {"outputfile", required_argument, 0, 'o'},
> - {"buffers", required_argument, 0, 'b'},
> {"testduration", required_argument, 0, 't'},
> {"polltimeout", required_argument, 0, 'p'},
> {"size", required_argument, 0, 's'},
> @@ -388,7 +461,6 @@ static void process_command_line(int argc, char **argv)
> const char *help =
> " -v --verbosity=level verbosity level of GuC logging (0-3)\n"
> " -o --outputfile=name name of the output file, including the location, where logs will be stored\n"
> - " -b --buffers=num number of buffers to be maintained on logger side for storing logs\n"
> " -t --testduration=sec max duration in seconds for which the logger should run\n"
> " -p --polltimeout=ms polling timeout in ms, -1 == indefinite wait for the new data\n"
> " -s --size=MB max size of output file in MBs after which logging will be stopped\n"
> @@ -404,6 +476,11 @@ int main(int argc, char **argv)
> int nfds;
> int ret;
>
> + drm_fd = drm_open_driver(DRIVER_INTEL);
> + igt_assert(drm_fd != -1);
> + igt_assert_neq(asprintf(&gucfspath, "gt0/uc"), -1);
> +
> + get_guc_subbuf_info();
> process_command_line(argc, argv);
>
Can we parse options before open driver? When run with -h, open driver
is not expected.
> init_main_thread();
> @@ -466,5 +543,7 @@ int main(int argc, char **argv)
> free(read_buffer);
> close(relay_fd);
> close(outfile_fd);
> + free(gucfspath);
> + close(drm_fd);
> igt_exit();
> }
More information about the igt-dev
mailing list