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