[igt-dev] [PATCH i-g-t] lib/kmod: reimplement kmsg_dump()

[Petri Latvala]

On Thu, Sep 19, 2019 at 06:07:23PM -0700, Lucas De Marchi wrote:
> /dev/kmsg is record-oriented rather than line-oriented. A short read in
> which the record doesn't fit will return -EINVAL and getline() will stop
> working. This is in general not a problem since the (default) stdio
> buffer is bigger than the maximum record size (4096). However let's
> abide by the kernel ABI rather than relying on the libc buffer size.
> 
> While reimplementing, fix the following issues that made me look to the
> implementation in the first place:
> 
> 1) we were skipping 1 char in the message, producing messages like the
>    one below (see the missing i in intel_pch_type):
> 	(i915_selftest:3861) igt_kmod-WARNING: ntel_pch_type [i915]] Found Tiger Lake LP PCH
> 
> 2) we were printing the key=val pair of kmsg as if it was part of the
> messsages, and even mangling the result looking for a ':':
> 	(i915_selftest:3861) igt_kmod-WARNING: 000:00:02.0
> 
> The ABI for /dev/kmsg stands:
> 	Accessing the buffer:
> 		Every read() from the opened device node receives one record
> 		of the kernel's printk buffer.
> 
> 		[ ... ]
> 
> 		Future extensions might add more comma separated values before
> 		the terminating ';'. Unknown fields and values should be
> 		gracefully ignored.
> 
> 		The human readable text string starts directly after the ';'
> 		and is terminated by a '\n'. Untrusted values derived from
> 		hardware or other facilities are printed, therefore
> 		all non-printable characters and '\' itself in the log message
> 		are escaped by "\x00" C-style hex encoding.
> 
> 		A line starting with ' ', is a continuation line, adding
> 		key/value pairs to the log message, which provide the machine
> 		readable context of the message, for reliable processing in
> 		userspace.
> 
> Now the line in (1) print as:
> 	(i915_selftest:5070) igt_kmod-WARNING: [drm:intel_pch_type [i915]] Found Tiger Lake LP PCH
> 
> This also fixes a double close on fclose() already closes the file
> descriptor.
> 
> Signed-off-by: Lucas De Marchi <lucas.demarchi at intel.com>
> ---
>  lib/igt_kmod.c | 43 ++++++++++++++++++++++++++-----------------
>  1 file changed, 26 insertions(+), 17 deletions(-)
> 
> diff --git a/lib/igt_kmod.c b/lib/igt_kmod.c
> index 91662eb3..01faca39 100644
> --- a/lib/igt_kmod.c
> +++ b/lib/igt_kmod.c
> @@ -374,25 +374,34 @@ igt_i915_driver_unload(void)
>  
>  static void kmsg_dump(int fd)
>  {
> -	FILE *file;
> -
> -	file = NULL;
> -	if (fd != -1)
> -		file = fdopen(fd, "r");
> -	if (file) {
> -		size_t len = 0;
> -		char *line = NULL;
> -
> -		while (getline(&line, &len, file) != -1) {
> -			char *start = strchr(line, ':');
> -			if (start)
> -				igt_warn("%s", start + 2);
> -		}
> +	char record[4096 + 1];
>  
> -		free(line);
> -		fclose(file);
> -	} else {
> +	if (fd == -1) {
>  		igt_warn("Unable to retrieve kernel log (from /dev/kmsg)\n");
> +		return;
> +	}
> +
> +	record[sizeof(record) - 1] = '\0';
> +
> +	for (;;) {
> +		const char *start, *end;
> +		ssize_t r;
> +
> +		r = read(fd, record, sizeof(record) - 1);
> +		if (r < 0) {
> +			if (errno == EINTR)
> +				continue;
> +			if (errno != EAGAIN)
> +				igt_warn("kmsg truncated due to unknown error: %m\n");
> +			break;
> +		}
> +
> +		start = strchr(record, ';');
> +		if (start) {
> +			start++;
> +			end = strchrnul(start, '\n');
> +			igt_warn("%.*s\n", (int)(end - start), start);
> +		}
>  	}
>  }


Reviewed-by: Petri Latvala <petri.latvala at intel.com>


Can I interest you in refactoring this and parse_dmesg_line() in
runner/resultgen.c together? :P