[Intel-gfx] [PATCH i-g-t v2] lib/igt_core: Add kmsg capture and dumping

[Joonas Lahtinen]

On to, 2015-11-19 at 11:32 +0000, Chris Wilson wrote:
> On Thu, Nov 19, 2015 at 12:35:23PM +0200, Joonas Lahtinen wrote:
> > +static void _igt_kmsg_capture_reset(void)
> > +{
> > +	if (igt_kmsg_capture_fd != -1)
> > +		close(igt_kmsg_capture_fd);
> > +
> > +	igt_kmsg_capture_fd = open("/dev/kmsg",
> > +				   O_RDONLY | O_NONBLOCK);
> 
> We should O_CLOEXEC as well.
> 

Fixed.

> > +
> > +	if (igt_kmsg_capture_fd == -1)
> > +		return;
> > +
> > +	lseek(igt_kmsg_capture_fd, 0, SEEK_END);
> > +
> > +	if (igt_kmsg_capture_dump_buf == NULL)
> > +		igt_kmsg_capture_dump_buf =
> > +			malloc(IGT_KMSG_CAPTURE_DUMP_BUF_SIZE);
> > +
> > +	if (igt_kmsg_capture_dump_buf == NULL)
> > +		igt_warn("Unable to allocate memory, "
> > +			 "will not dump kmsg.\n");
> 
> If we allocate first, then bail, we know if we have the fd we have
> the
> buffer as well.
> 

I was thinking we would still perform as much of the actions that would
be done if we were able to dump the kmsg, for consistency. That is why
the buffer allocation is handled separately. But maybe it's bit
overkill.

> > +}
> > +
> > +static int _igt_kmsg_capture_dump(bool notify_empty, int
> > show_priority)
> > +{
> > +	size_t nbytes;
> > +	int nlines;
> > +	int prefix;
> > +	int facility;
> > +	int priority;
> > +	char *p;
> > +	int c;
> > +
> > +	if (igt_kmsg_capture_fd == -1 ||
> > +	    igt_kmsg_capture_dump_buf == NULL)
> > +		return 0;
> 
> i.e. we can just do if (fd == -1) return 0;
> 
> > +
> > +	nlines = 0;
> > +	do {
> > +		errno = 0;
> > +		nbytes = read(igt_kmsg_capture_fd,
> > +			      igt_kmsg_capture_dump_buf,
> > +			      IGT_KMSG_CAPTURE_DUMP_BUF_SIZE);
> > +
> > +		if (nbytes == -1)
> > +			continue;
> > +
> > +		sscanf(igt_kmsg_capture_dump_buf, "%d;", &prefix);
> > +		priority = prefix & 0x7;
> > +
> > +		if (priority > show_priority)
> > +			continue;
> > +
> > +		if (!nlines)
> > +			fprintf(stderr, "**** KMSG ****\n");
> > +
> > +		p = strchr(igt_kmsg_capture_dump_buf, ';') + 1;
> > +		while (p - igt_kmsg_capture_dump_buf < nbytes) {
> > +			if (*p != '\\') {
> > +				fputc(*p++, stderr);
> > +				continue;
> > +			}
> > +			sscanf(p, "\\x%x", &c);
> > +			fputc(c, stderr);
> > +			p += 4;
> 
> Maybe:
> 	/* Decode non-printable characters escaped by '\x01' */
> 	int c = *p++;
> 	if (c == '\\') {
> 		if (p - igt_kmgs_capture_dump_buf > nbytes - 3)
> 			break;
> 		sscanf(p+1, "%x", &c);
> 		p += 3;
> 	}
> 	fputc(c, stderr);
> 

I'll simplify this bit.

> > +		}
> > +		nlines++;
> > +	} while(errno == 0);
> > +
> > +	if (nlines) {
> > +		fprintf(stderr, "****  END  ****\n");
> > +	} else {
> > +		if (notify_empty)
> > +			fprintf(stderr, "No kmsg.\n");
> > +	}
> > +
> > +	if (errno != EAGAIN)
> > +		fprintf(stderr, "Error: Incomplete kmsg!\n");
> > +
> > +	close(igt_kmsg_capture_fd);
> > +	igt_kmsg_capture_fd = -1;
> > +
> > +	free(igt_kmsg_capture_dump_buf);
> > +	igt_kmsg_capture_dump_buf = NULL;
> 
> Hmm, single-shot.
> 
> I have in mind more of an automatic debug feature coupled with error
> detection like how we automatically go back and print the debug log
> if
> the test fails. As I understand it, with a FAIL (KMSG) we currently
> lose
> any lower priority output.
> 

Yeah, unless we allocate buffers and store when we start reading, it
has to be dumped as we read. This also causes the one thing I don't
like in the current implementation is that the KMSG appears before the
debug output. The /dev/kmsg doesn't want to be seeked (even the
documentation states that, attempted that initially regardless), so our
only option is to allocate buffers dynamically or estimate maximum
buffer size and go with that.

> The integration looks good to me otherwise. But someone else will
> have
> to vouch for test-runner/piglit handling of "FAIL (KMSG)" (I used
> WARN).

I think we could make NOTICE and WARN cause WARN (KMSG) and rest a FAIL
(KMSG) ?

Regards, Joonas

> -Chris
> 
-- 
Joonas Lahtinen
Open Source Technology Center
Intel Corporation