| 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 | |
| 14 | use strict 'refs'; |
| 15 | use strict subs; |
| 16 | |
| 17 | use Getopt::Long; |
| 18 | use 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 | #______________________________________________________________________________ |
| 29 | sub 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 | #______________________________________________________________________________ |
| 90 | sub usage { |
| 91 | |
| 92 | # ***** when editing, be careful to not put tabs in the string printed: |
| 93 | |
| 94 | print STDERR |
| 95 | " |
| 96 | usage: |
| 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 | |
| 167 | if (!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 | |
| 187 | if ($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 | # - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - |
| 197 | if ($help){ |
| 198 | |
| 199 | &usage; |
| 200 | |
| 201 | exit $EX_OK; |
| 202 | } |
| 203 | |
| 204 | |
| 205 | # - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - |
| 206 | |
| 207 | if ($version) { |
| 208 | print STDERR "\n$script_name $VUFX\n\n"; |
| 209 | print STDERR "\n"; |
| 210 | |
| 211 | exit $EX_OK; |
| 212 | } |
| 213 | |
| 214 | |
| 215 | # - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - |
| 216 | if ($#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 | |
| 253 | LINE: |
| 254 | while ($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 | |
| 504 | if (! $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 | |
| 527 | if (@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 | |
| 535 | if (@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 | } |