1#!/usr/bin/perl
2# SPDX-License-Identifier: GPL-2.0
3#
4# Copyright 2020, 2022 Sony Corporation
5#
6# Author: Frank Rowand
7
8# This program is meant to be an aid to reading the verbose output of
9# on the console log that results from executing the Linux kernel
10# devicetree unittest (drivers/of/unitest.c).
11
12$VUFX = "230211a";
13
14use strict 'refs';
15use strict subs;
16
17use Getopt::Long;
18use Text::Wrap;
19
20# strip off everything before final "/"
21(undef, $script_name) = split(/^.*\//, $0);
22
23# following /usr/include/sysexits.h
24$EX_OK=0;
25$EX_USAGE=64;
26
27
28#______________________________________________________________________________
29sub compare {
30	my ($expect, $got) = @_;
31	my $expect_next;
32	my $expect_next_lit;
33	my $got_next;
34	my $type;
35
36	while ($expect) {
37
38		($expect_next, $type) = split(/<</, $expect);
39		($type) = split(/>>/, $type);
40		$expect =~ s/^.*?>>//;	# '?' is non-greedy, minimal match
41
42		# literal, ignore all metacharacters when used in a regex
43		$expect_next_lit = quotemeta($expect_next);
44
45		$got_next = $got;
46		$got_next =~ s/^($expect_next_lit).*/\1/;
47		$got       =~ s/^$expect_next_lit//;
48
49		if ($expect_next ne $got_next) {
50			return 0;
51		}
52
53		if ($type eq "int") {
54			if ($got =~ /^[+-]*[0-9]+/) {
55				$got =~ s/^[+-]*[0-9]+//;
56			} else {
57				return 0;
58			}
59		} elsif ($type eq "hex") {
60			if ($got =~ /^(0x)*[0-9a-f]+/) {
61				$got =~ s/^(0x)*[0-9a-f]+//;
62			} else {
63				return 0;
64			}
65		} elsif ($type eq "all") {
66			return 1;
67		} elsif ($type eq "") {
68			if ($expect_next ne $got_next) {
69				return 0;
70			} else {
71				return 1;
72			}
73		} else {
74			$internal_err++;
75			print "** ERROR: special pattern not recognized: <<$type>>, CONSOLE_LOG line: $.\n";
76			return 0;
77		}
78
79	}
80
81	# should not get here
82	$internal_err++;
83	print "** ERROR: $script_name internal error, at end of compare(), CONSOLE_LOG line: $.\n";
84
85	return 0;
86}
87
88
89#______________________________________________________________________________
90sub usage {
91
92# ***** when editing, be careful to not put tabs in the string printed:
93
94	print STDERR
95"
96usage:
97
98  $script_name CONSOLE_LOG
99
100     -h                print program usage
101    --help             print program usage
102    --hide-expect      suppress output of EXPECTed lines
103    --line-num         report line number of CONSOLE_LOG
104    --no-expect-stats  do not report EXPECT statistics
105    --no-strip-ts      do not strip leading console timestamps
106    --verbose          do not suppress EXPECT begin and end lines
107    --version          print program version and exit
108
109
110  Process a console log for EXPECTed test related messages to either
111  highlight expected devicetree unittest related messages or suppress
112  the messages.  Leading console timestamps will be stripped.
113
114  Various unittests may trigger kernel messages from outside the
115  unittest code.  The unittest annotates that it expects the message
116  to occur with an 'EXPECT \\ : text' (begin) before triggering the
117  message, and an 'EXPECT / : text' (end) after triggering the message.
118
119  If an expected message does not occur, that will be reported.
120
121  For each expected message, the 'EXPECT \\ : text' (begin) and
122  'EXPECT / : text' (end), 'text' will contain the message text.
123
124  If 'EXPECT \\' (begin) and 'EXPECT /' (end) lines do not contain
125  matching 'text', that will be reported.
126
127  If EXPECT lines are nested, 'EXPECT /' (end) lines must be in the
128  reverse order of the corresponding 'EXPECT \\' (begin) lines.
129
130  'EXPECT \\ : text' (begin) and 'EXPECT / : text' (end) lines can
131  contain special patterns in 'text':
132
133     <<int>> matches: [+-]*[0-9]+
134     <<hex>> matches: (0x)*[0-9a-f]+
135     <<all>> matches: anything to end of line
136
137  'EXPECT \\' (begin) and 'EXPECT /' (end) lines are suppressed.
138
139  A prefix is added to every line of output:
140
141    'ok ' Line matches an enclosing EXPECT begin/end pair
142
143    '** ' Line reports $script_name warning or error
144
145    '-> ' Line reports start or end of the unittests
146
147    '>> ' Line reports a unittest test FAIL
148
149    '   ' Lines that are not otherwise prefixed
150
151  Issues detected in CONSOLE_LOG are reported to STDOUT, not to STDERR.
152
153  Known Issues:
154
155    --line-num causes the CONSOLE_LOG line number to be printed in 4 columns.
156       If CONSOLE_LOG contains more than 9999 lines then more columns will be
157       used to report the line number for lines greater than 9999 (eg for
158       lines 10000 - 99999, 5 columns will be used).
159";
160
161	return {};
162}
163
164#______________________________________________________________________________
165#______________________________________________________________________________
166
167if (!GetOptions(
168	"h"               => \$help,
169	"help"            => \$help,
170	"hide-expect"     => \$hide_expect,
171	"line-num"        => \$print_line_num,
172	"no-expect-stats" => \$no_expect_stats,
173	"no-strip-ts"     => \$no_strip_ts,
174	"verbose"         => \$verbose,
175	"version"         => \$version,
176	)) {
177	print STDERR "\n";
178	print STDERR "ERROR processing command line options\n";
179	print STDERR "\n";
180	print STDERR "For help, type '$script_name --help'\n";
181	print STDERR "\n";
182
183	exit $EX_OK;
184}
185
186
187if ($no_strip_ts) {
188	$strip_ts = 1;
189	$no_strip_ts = 0;
190} else {
191	$strip_ts = 0;
192	$no_strip_ts = 1;
193}
194
195
196# - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
197if ($help){
198
199	&usage;
200
201	exit $EX_OK;
202}
203
204
205# - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
206
207if ($version) {
208	print STDERR "\n$script_name  $VUFX\n\n";
209	print STDERR "\n";
210
211	exit $EX_OK;
212}
213
214
215# - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
216if ($#ARGV != 0) {
217
218	# Limit input files to exactly one.
219	#
220	# 'while ($line = <ARGV>) {' in the code below supports multiple file
221	# names on the command line, but the EXPECT statistics are reported
222	# once for all input - it is not an expected use case to generate one
223	# set of statistics for multiple input files.
224
225	print STDERR "\n";
226	print STDERR "Required arguments: CONSOLE_LOG\n";
227	print STDERR "\n";
228
229	exit $EX_USAGE;
230}
231
232
233#______________________________________________________________________________
234
235# Patterns to match 'EXPECT \ : ' (begin) and 'EXPECT / : ' (end)
236#
237# $exp_* are used as regex match patterns,
238# so '\\\\' in $exp_begin matches a single '\'
239# quotemeta() does not do the right thing in this case
240#
241# $pr_fmt is the prefix that unittest prints for every message
242
243$pr_fmt = "### dt-test ### ";
244$exp_begin = "${pr_fmt}EXPECT \\\\ : ";
245$exp_end   = "${pr_fmt}EXPECT / : ";
246$expnot_begin = "${pr_fmt}EXPECT_NOT \\\\ : ";
247$expnot_end   = "${pr_fmt}EXPECT_NOT / : ";
248
249
250$line_num = "";
251$timestamp = "";
252
253LINE:
254while ($line = <ARGV>) {
255
256	chomp $line;
257
258	$suppress_line = 0;
259
260	$prefix = "  ";  ## 2 characters
261
262
263	if ($strip_ts) {
264
265		$timestamp = $line;
266
267		if ($timestamp =~ /^\[\s*[0-9]+\.[0-9]*\] /) {
268			($timestamp, $null) = split(/]/, $line);
269			$timestamp = $timestamp . "] ";
270
271		} else {
272			$timestamp = "";
273		}
274	}
275
276	$line =~ s/^\[\s*[0-9]+\.[0-9]*\] //;
277
278
279	# -----  find EXPECT begin
280
281	if ($line =~ /^\s*$exp_begin/) {
282		$data = $line;
283		$data =~ s/^\s*$exp_begin//;
284		push @exp_begin_stack, $data;
285
286		if ($verbose) {
287			if ($print_line_num) {
288				$line_num = sprintf("%4s ", $.);
289			}
290			printf "%s %s%s%s\n", $prefix, $line_num,  $timestamp, $line;
291		}
292
293		next LINE;
294	}
295
296
297	# -----  find EXPECT end
298
299	if ($line =~ /^\s*$exp_end/) {
300		$data = $line;
301		$data =~ s/^\s*$exp_end//;
302
303		if ($verbose) {
304			if ($print_line_num) {
305				$line_num = sprintf("%4s ", $.);
306			}
307			printf "%s %s%s%s\n", $prefix, $line_num,  $timestamp, $line;
308		}
309
310		$found = 0;
311		$no_begin = 0;
312		if (@exp_found_or_begin > 0) {
313			$begin = pop @exp_found_or_begin;
314			if (compare($data, $begin)) {
315				$found = 1;
316				$exp_found++;
317			}
318		} elsif (@begin > 0) {
319			$begin = pop @exp_begin_stack;
320		} else {
321			$no_begin = 1;
322		}
323
324		if ($no_begin) {
325
326			$exp_missing_begin++;
327			print "** ERROR: EXPECT end without matching EXPECT begin:\n";
328			print "       end ---> $line\n";
329
330		} elsif (! $found) {
331
332			if ($print_line_num) {
333				$line_num = sprintf("%4s ", $.);
334			}
335
336			$exp_missing++;
337			printf "** %s%s$script_name WARNING - not found ---> %s\n",
338					$line_num,  $timestamp, $data;
339
340		} elsif (! compare($data, $begin) and ($data ne $begin)) {
341
342			$exp_missing_end++;
343			print "** ERROR: EXPECT end does not match EXPECT begin:\n";
344			print "       begin -> $begin\n";
345			print "       end ---> $line\n";
346
347		}
348
349		next LINE;
350	}
351
352
353	# -----  find EXPECT_NOT begin
354
355	if ($line =~ /^\s*$expnot_begin/) {
356		$data = $line;
357		$data =~ s/^\s*$expnot_begin//;
358		push @expnot_begin_stack, $data;
359
360		if ($verbose) {
361			if ($print_line_num) {
362				$line_num = sprintf("%4s ", $.);
363			}
364			printf "%s %s%s%s\n", $prefix, $line_num,  $timestamp, $line;
365		}
366
367		next LINE;
368	}
369
370
371	# -----  find EXPECT_NOT end
372
373	if ($line =~ /^\s*$expnot_end/) {
374		$data = $line;
375		$data =~ s/^\s*$expnot_end//;
376
377		if ($verbose) {
378			if ($print_line_num) {
379				$line_num = sprintf("%4s ", $.);
380			}
381			printf "%s %s%s%s\n", $prefix, $line_num,  $timestamp, $line;
382		}
383
384		$found = 0;
385		$no_begin = 0;
386		if (@expnot_found_or_begin > 0) {
387			$begin = pop @expnot_found_or_begin;
388			if (compare($data, $begin)) {
389				$found = 1;
390				$expnot_found++;
391			}
392		} elsif (@expnot_begin_stack <= 0) {
393			$no_begin = 1;
394		}
395
396		if ($no_begin) {
397
398			$expnot_missing_begin++;
399			print "** ERROR: EXPECT_NOT end without matching EXPECT_NOT begin:\n";
400			print "       end ---> $line\n";
401
402		}
403
404		if ($found) {
405
406			if ($print_line_num) {
407				$line_num = sprintf("%4s ", $.);
408			}
409
410			printf "** %s%s$script_name WARNING - next line matches EXPECT_NOT\n",
411					$line_num,  $timestamp;
412			printf "** %s%s%s\n", $line_num,  $timestamp, $line;
413
414		} else {
415
416			$expnot_missing++;
417
418		}
419
420		if (@expnot_begin_stack > 0) {
421			$begin = pop @expnot_begin_stack;
422
423			if (! compare($data, $begin) and ($data ne $begin)) {
424
425				$expnot_missing_end++;
426				print "** ERROR: EXPECT_NOT end does not match EXPECT_NOT begin:\n";
427				print "       begin -> $begin\n";
428				print "       end ---> $line\n";
429
430			}
431		}
432
433		next LINE;
434	}
435
436
437	# -----  not an EXPECT line
438
439	if (($line =~ /^${pr_fmt}start of unittest - you will see error messages$/) ||
440	    ($line =~ /^${pr_fmt}end of unittest - [0-9]+ passed, [0-9]+ failed$/ )   ) {
441		$prefix = "->"; # 2 characters
442	} elsif ($line =~ /^${pr_fmt}FAIL /) {
443		$unittest_fail++;
444		$prefix = ">>"; # 2 characters
445	}
446
447	$found = 0;
448	foreach $begin (@exp_begin_stack) {
449		if (compare($begin, $line)) {
450			$found = 1;
451			last;
452		}
453	}
454
455	if ($found) {
456		$begin = shift @exp_begin_stack;
457		while (! compare($begin, $line)) {
458			push @exp_found_or_begin, $begin;
459			$begin = shift @exp_begin_stack;
460		}
461		push @exp_found_or_begin, $line;
462
463		if ($hide_expect) {
464			$suppress_line = 1;
465		}
466		$prefix = "ok"; # 2 characters
467	}
468
469
470	$found = 0;
471	foreach $begin (@expnot_begin_stack) {
472		if (compare($begin, $line)) {
473			$found = 1;
474			last;
475		}
476	}
477
478	if ($found) {
479		$begin = shift @begin;
480		while (! compare($begin, $line)) {
481			push @expnot_found_or_begin, $begin;
482			$begin = shift @begin;
483		}
484		push @expnot_found_or_begin, $line;
485
486		if ($hide_expect) {
487			$suppress_line = 1;
488		}
489		$prefix = "**"; # 2 characters
490	}
491
492
493	if ($suppress_line) {
494		next LINE;
495	}
496
497	if ($print_line_num) {
498		$line_num = sprintf("%4s ", $.);
499	}
500
501	printf "%s %s%s%s\n", $prefix, $line_num,  $timestamp, $line;
502}
503
504if (! $no_expect_stats) {
505	print  "\n";
506	print  "** EXPECT statistics:\n";
507	print  "**\n";
508	printf "**   non-zero values expected:\n";
509	print  "**\n";
510	printf "**     EXPECT found              : %4i\n", $exp_found;
511	printf "**     EXPECT_NOT not found      : %4i\n", $expnot_missing;
512	print  "**\n";
513	printf "**   zero values expected:\n";
514	print  "**\n";
515	printf "**     EXPECT not found          : %4i\n", $exp_missing;
516	printf "**     missing EXPECT begin      : %4i\n", $exp_missing_begin;
517	printf "**     missing EXPECT end        : %4i\n", $exp_missing_end;
518	print  "**\n";
519	printf "**     EXPECT_NOT found          : %4i\n", $expnot_found;
520	printf "**     missing EXPECT_NOT begin  : %4i\n", $expnot_missing_begin;
521	printf "**     missing EXPECT_NOT end    : %4i\n", $expnot_missing_end;
522	print  "**\n";
523	printf "**     unittest FAIL             : %4i\n", $unittest_fail;
524	printf "**     internal error            : %4i\n", $internal_err;
525}
526
527if (@exp_begin_stack) {
528	print "** ERROR: EXPECT begin without matching EXPECT end:\n";
529	print "          This list may be misleading.\n";
530	foreach $begin (@exp_begin_stack) {
531		print "       begin ---> $begin\n";
532	}
533}
534
535if (@expnot_begin_stack) {
536	print "** ERROR: EXPECT_NOT begin without matching EXPECT_NOT end:\n";
537	print "          This list may be misleading.\n";
538	foreach $begin (@expnot_begin_stack) {
539		print "       begin ---> $begin\n";
540	}
541}
542