diff --git a/Changes b/Changes index 82fe61b54..f1bc12cc2 100644 --- a/Changes +++ b/Changes @@ -8,6 +8,28 @@ The changes in each Verilator version are described below. The contributors that suggested a given feature are shown in []. Thanks! +Verilator 4.214 2021-10-17 +========================== + +* Add profile-guided optmization of mtasks (#3150). +* Verilator_gantt has removed the ASCII graphics, use the VCD output instead. +* Verilator_gantt now shows the predicted mtask times, eval times, and additional statistics. +* Verilator_gantt data files now include processor information, to allow later processing. +* Support displaying x and z in $display task (#3107) (#3109). [Iru Cai] +* Fix verilator_profcfunc profile accounting (#3115). +* Fix display has no time units on class function (#3116). [Damien Pretet] +* Fix removing if statement with side effect in condition (#3131). [Alexander Grobman] +* Fix --waiver-output for multiline warnings (#2429) (#3141). [Keith Colbert] +* Fix internal error on bad widths (#3140) (#3145). [Zhanglei Wang] +* Fix crash on clang 12/13 (#3148). [Kouping Hsu] +* Fix cygwin compile error due to missing -std=gnu++14 (#3149). [Sun Kim] +* Fix $urandom_range when the range is 0 ... UINT_MAX (#3161). [Iru Cai] +* Fix constructor-parameter argument comma-separation in C++ (#3162). [Matthew Ballance] +* Fix missing install of vl_file_copy/vl_hier_graph (#3165). [Popolon] +* Fix calling new with arguments in same class (#3166). [Matthew Ballance] +* Fix false EOFNEWLINE warning when DOS carriage returns present (#3171). + + Verilator 4.212 2021-09-01 ========================== diff --git a/Makefile.in b/Makefile.in index 7b09873c8..c381eda44 100644 --- a/Makefile.in +++ b/Makefile.in @@ -118,23 +118,6 @@ INFOS = verilator.html verilator.pdf INFOS_OLD = README README.html README.pdf -INST_PROJ_FILES = \ - bin/verilator \ - bin/verilator_ccache_report \ - bin/verilator_coverage \ - bin/verilator_gantt \ - bin/verilator_includer \ - bin/verilator_profcfunc \ - include/verilated.mk \ - include/*.[chv]* \ - include/gtkwave/*.[chv]* \ - include/vltstd/*.[chv]* \ - -INST_PROJ_BIN_FILES = \ - bin/verilator_bin$(EXEEXT) \ - bin/verilator_bin_dbg$(EXEEXT) \ - bin/verilator_coverage_bin_dbg$(EXEEXT) \ - EXAMPLES_FIRST = \ examples/make_hello_c \ examples/make_hello_sc \ @@ -142,7 +125,7 @@ EXAMPLES_FIRST = \ EXAMPLES = $(EXAMPLES_FIRST) $(filter-out $(EXAMPLES_FIRST), $(sort $(wildcard examples/*))) # See uninstall also - don't put wildcards in this variable, it might uninstall other stuff -VL_INST_MAN_FILES = verilator.1 verilator_coverage.1 verilator_gantt.1 verilator_profcfunc.1 +VL_INST_MAN_FILES = verilator.1 verilator_coverage.1 default: all all: all_nomsg msg_test @@ -224,8 +207,10 @@ VL_INST_INC_SRCDIR_FILES = \ include/vltstd/*.[chv]* \ VL_INST_DATA_SRCDIR_FILES = \ - examples/*/*.[chv]* examples/*/Makefile* \ - examples/*/CMakeLists.txt + examples/*/*.[chv]* \ + examples/*/CMakeLists.txt \ + examples/*/Makefile* \ + examples/*/vl_* \ installbin: $(MKINSTALLDIRS) $(DESTDIR)$(bindir) @@ -369,6 +354,9 @@ clang-format: PY_PROGRAMS = \ bin/verilator_ccache_report \ + bin/verilator_difftree \ + bin/verilator_gantt \ + bin/verilator_profcfunc \ examples/xml_py/vl_file_copy \ examples/xml_py/vl_hier_graph \ docs/guide/conf.py \ diff --git a/bin/verilator b/bin/verilator index 0a9ceaf71..fbd06550a 100755 --- a/bin/verilator +++ b/bin/verilator @@ -34,11 +34,11 @@ my $opt_quiet_exit; # No arguments can't do anything useful. Give help if ($#ARGV < 0) { - pod2usage(-exitstatus=>2, -verbose=>0); + pod2usage(-exitstatus => 2, -verbose => 0); } # Insert debugging options up front -push @ARGV, (split ' ',$ENV{VERILATOR_TEST_FLAGS}||""); +push @ARGV, (split ' ', $ENV{VERILATOR_TEST_FLAGS} || ""); # We sneak a look at the flags so we can do some pre-environment checks # All flags will hit verilator... @@ -46,7 +46,7 @@ foreach my $sw (@ARGV) { push @Opt_Verilator_Sw, $sw; } -Getopt::Long::config("no_auto_abbrev","pass_through"); +Getopt::Long::config("no_auto_abbrev", "pass_through"); if (! GetOptions( # Major operating modes "help" => \&usage, @@ -60,7 +60,7 @@ if (! GetOptions( # Additional parameters "<>" => sub {}, # Ignored )) { - pod2usage(-exitstatus=>2, -verbose=>0); + pod2usage(-exitstatus => 2, -verbose => 0); } if ($opt_gdbbt && !gdb_works()) { @@ -73,12 +73,12 @@ if ($opt_gdbbt && !gdb_works()) { # Starting with that, escape all special chars for the shell; # The shell will undo the escapes and the verilator binary should # then see exactly the contents of @Opt_Verilator_Sw. -my @quoted_sw = map {sh_escape($_)} @Opt_Verilator_Sw; +my @quoted_sw = map { sh_escape($_) } @Opt_Verilator_Sw; if ($opt_gdb) { # Generic GDB interactive run (aslr_off() - .($ENV{VERILATOR_GDB}||"gdb") - ." ".verilator_bin() + . ($ENV{VERILATOR_GDB} || "gdb") + . " " . verilator_bin() # Note, uncomment to set breakpoints before running: # ." -ex 'break main'" @@ -87,42 +87,41 @@ if ($opt_gdb) { # escapes as you would expect in a double-quoted string. # That's not true for a single-quoted string, where \' # actually terminates the string -- not what we want! - ." -ex \"run ".join(' ', @quoted_sw)."\"" - ." -ex 'set width 0'" - ." -ex 'bt'"); + . " -ex \"run " . join(' ', @quoted_sw) . "\"" + . " -ex 'set width 0'" + . " -ex 'bt'"); } elsif ($opt_rr) { # Record with rr run (aslr_off() - ."rr record ".verilator_bin() - ." ".join(' ', @quoted_sw)); + . "rr record " . verilator_bin() + . " " . join(' ', @quoted_sw)); } elsif ($opt_gdbbt && $Debug) { # Run under GDB to get gdbbt run (aslr_off() - ."gdb" - ." ".verilator_bin() - ." --batch --quiet --return-child-result" - ." -ex \"run ".join(' ', @quoted_sw)."\"" - ." -ex 'set width 0'" - ." -ex 'bt' -ex 'quit'"); + . "gdb" + . " " . verilator_bin() + . " --batch --quiet --return-child-result" + . " -ex \"run " . join(' ', @quoted_sw)."\"" + . " -ex 'set width 0'" + . " -ex 'bt' -ex 'quit'"); } elsif ($Debug) { # Debug - run(aslr_off() - .verilator_bin()." ".join(' ',@quoted_sw)); + run(aslr_off() . verilator_bin() . " " . join(' ', @quoted_sw)); } else { # Normal, non gdb - run(verilator_bin()." ".join(' ',@quoted_sw)); + run(verilator_bin() . " " . join(' ', @quoted_sw)); } #---------------------------------------------------------------------- sub usage { - pod2usage(-verbose=>2, -exitval=>0, -output=>\*STDOUT); + pod2usage(-verbose => 2, -exitval => 0, -output => \*STDOUT); } sub debug { shift; my $level = shift; - $Debug = $level||3; + $Debug = $level || 3; } ####################################################################### @@ -163,13 +162,13 @@ sub verilator_bin { sub gdb_works { $! = undef; # Cleanup -x system("gdb /bin/echo" - ." --batch-silent --quiet --return-child-result" - ." -ex 'run -n'" # `echo -n` - ." -ex 'set width 0'" - ." -ex 'bt'" - ." -ex 'quit'"); + . " --batch-silent --quiet --return-child-result" + . " -ex 'run -n'" # `echo -n` + . " -ex 'set width 0'" + . " -ex 'bt'" + . " -ex 'quit'"); my $status = $?; - return $status==0; + return $status == 0; } sub aslr_off { @@ -185,7 +184,7 @@ sub run { # Run command, check errors my $command = shift; $! = undef; # Cleanup -x - print "\t$command\n" if $Debug>=3; + print "\t$command\n" if $Debug >= 3; system($command); my $status = $?; if ($status) { @@ -193,7 +192,7 @@ sub run { warn "%Error: verilator: Misinstalled, or VERILATOR_ROOT might need to be in environment\n"; } if ($Debug) { # For easy rerunning - warn "%Error: export VERILATOR_ROOT=".($ENV{VERILATOR_ROOT}||"")."\n"; + warn "%Error: export VERILATOR_ROOT=" . ($ENV{VERILATOR_ROOT} || "") . "\n"; warn "%Error: $command\n"; } if ($status & 127) { @@ -201,13 +200,13 @@ sub run { || ($status & 127) == 8 # SIGFPA || ($status & 127) == 11) { # SIGSEGV warn "%Error: Verilator internal fault, sorry. " - ."Suggest trying --debug --gdbbt\n" if !$Debug; + . "Suggest trying --debug --gdbbt\n" if !$Debug; } elsif (($status & 127) == 6) { # SIGABRT warn "%Error: Verilator aborted. " - ."Suggest trying --debug --gdbbt\n" if !$Debug; + . "Suggest trying --debug --gdbbt\n" if !$Debug; } else { warn "%Error: Verilator threw signal $status. " - ."Suggest trying --debug --gdbbt\n" if !$Debug; + . "Suggest trying --debug --gdbbt\n" if !$Debug; } } if (!$opt_quiet_exit && ($status != 256 || $Debug)) { # i.e. not normal exit(1) @@ -448,6 +447,7 @@ description of these arguments. +verilator+prof+threads+file+ Set profile filename +verilator+prof+threads+start+ Set profile starting point +verilator+prof+threads+window+ Set profile duration + +verilator+prof+vlt+file+ Set profile guided filename +verilator+rand+reset+ Set random reset technique +verilator+seed+ Set random seed +verilator+V Verbose version and config diff --git a/bin/verilator_coverage b/bin/verilator_coverage index ab76d15ba..0ec1f1bac 100755 --- a/bin/verilator_coverage +++ b/bin/verilator_coverage @@ -30,7 +30,7 @@ $Debug = 0; # No arguments can't do anything useful. Give help if ($#ARGV < 0) { - pod2usage(-exitstatus=>2, -verbose=>0); + pod2usage(-exitstatus => 2, -verbose => 0); } # We sneak a look at the flags so we can do some pre-environment checks @@ -40,7 +40,7 @@ foreach my $sw (@ARGV) { push @Opt_Verilator_Sw, $sw; } -Getopt::Long::config("no_auto_abbrev","pass_through"); +Getopt::Long::config("no_auto_abbrev", "pass_through"); if (! GetOptions ( # Major operating modes "help" => \&usage, @@ -49,23 +49,23 @@ if (! GetOptions ( # Additional parameters "<>" => sub {}, # Ignored )) { - pod2usage(-exitstatus=>2, -verbose=>0); + pod2usage(-exitstatus => 2, -verbose => 0); } # Normal, non gdb run(verilator_coverage_bin() - ." ".join(' ',@Opt_Verilator_Sw)); + . " " . join(' ', @Opt_Verilator_Sw)); #---------------------------------------------------------------------- sub usage { - pod2usage(-verbose=>2, -exitval=>0, -output=>\*STDOUT); + pod2usage(-verbose => 2, -exitval => 0, -output => \*STDOUT); } sub debug { shift; my $level = shift; - $Debug = $level||3; + $Debug = $level || 3; } ####################################################################### @@ -107,7 +107,7 @@ sub run { # Run command, check errors my $command = shift; $! = undef; # Cleanup -x - print "\t$command\n" if $Debug>=3; + print "\t$command\n" if $Debug >= 3; system($command); my $status = $?; if ($status) { @@ -115,11 +115,11 @@ sub run { warn "%Error: verilator_coverage: Misinstalled, or VERILATOR_ROOT might need to be in environment\n"; } if ($Debug) { # For easy rerunning - warn "%Error: export VERILATOR_ROOT=".($ENV{VERILATOR_ROOT}||"")."\n"; + warn "%Error: export VERILATOR_ROOT=" . ($ENV{VERILATOR_ROOT} || "") . "\n"; warn "%Error: $command\n"; } if ($status & 127) { - if (($status & 127) == 8 || ($status & 127) == 11) { # SIGFPA or SIGSEGV + if (($status & 127) == 8 || ($status & 127) == 11) { # SIGFPA or SIGSEGV warn "%Error: Verilator_coverage internal fault, sorry.\n" if !$Debug; } elsif (($status & 127) == 6) { # SIGABRT warn "%Error: Verilator_coverage aborted.\n" if !$Debug; diff --git a/bin/verilator_difftree b/bin/verilator_difftree index 52b03d6bb..ab612bc5c 100755 --- a/bin/verilator_difftree +++ b/bin/verilator_difftree @@ -1,233 +1,139 @@ -#!/usr/bin/env perl -# See copyright, etc in below POD section. +#!/usr/bin/env python3 +# pylint: disable=C0103,C0114,C0116 ###################################################################### -use warnings; -use Getopt::Long; -use IO::File; -use Pod::Usage; -use strict; -use vars qw($Debug); +import argparse +import collections +import glob +import os.path +import re +import sys -#====================================================================== -# main -$Debug = 0; -my $Opt_A; -my $Opt_B; -my $Opt_Lineno = 1; -autoflush STDOUT 1; -autoflush STDERR 1; -Getopt::Long::config("no_auto_abbrev"); -if (! GetOptions( - "help" => \&usage, - "debug" => \&debug, - "<>" => \¶meter, - "lineno!" => \$Opt_Lineno, - )) { - die "%Error: Bad usage, try 'verilator_difftree --help'\n"; -} +def diff(a, b): -defined $Opt_A or die "%Error: No old diff filename\n"; -defined $Opt_B or die "%Error: No new diff filename\n"; + if not os.path.exists(a): + sys.exit("%Error: No old diff filename found: " + a) + if not os.path.exists(b): + sys.exit("%Error: No new diff filename found: " + b) --e $Opt_A or die "%Error: No old diff filename found: $Opt_A\n"; --e $Opt_B or die "%Error: No new diff filename found: $Opt_B\n"; + if os.path.isdir(a) and os.path.isdir(b): + diff_dir(a, b) + elif os.path.isfile(a) and os.path.isfile(b): + diff_file(a, b) + else: + sys.exit("%Error: Mix of files and dirs") -if (-d $Opt_A && -d $Opt_B) { - diff_dir($Opt_A, $Opt_B); -} elsif (-f $Opt_A && -f $Opt_B) { - diff_file($Opt_A, $Opt_B); -} else { - die "%Error: Mix of files and dirs\n"; -} -sub diff_dir { - my $a = shift; - my $b = shift; +def diff_dir(a, b): # Diff all files under two directories - my %files; + files = collections.defaultdict(lambda: {}) - foreach my $fn (glob("$a/*.tree")) { - (my $base = $fn) =~ s!.*/!!; - $files{$base}{a} = $fn; - } - foreach my $fn (glob("$b/*.tree")) { - (my $base = $fn) =~ s!.*/!!; - $files{$base}{b} = $fn; - } - my $any; - foreach my $base (sort (keys %files)) { - my $a = $files{$base}{a}; - my $b = $files{$base}{b}; - next if !$a || !$b; - print "="x70,"\n"; - print "= $a <-> $b\n"; - diff_file($a,$b); - $any = 1; - } - $any or warn("%Warning: No .tree files found that have similar base names:\n " - .join("\n ", sort keys %files),"\n"); -} + for fn in glob.glob(a + "/*.tree"): + base = re.sub(r'.*/', '', fn) + files[base]['a'] = fn + for fn in glob.glob(b + "/*.tree"): + base = re.sub(r'.*/', '', fn) + files[base]['b'] = fn -sub diff_file { - my $a = shift; - my $b = shift; + anyfile = False + for base in sorted(files.keys()): + a = files[base]['a'] + b = files[base]['b'] + if not a or not b: + continue + print("=" * 70) + print("= %s <-> %s" % (a, b)) + diff_file(a, b) + anyfile = True + if not anyfile: + sys.stderr.write( + "%Warning: No .tree files found that have similar base names\n") + + +def diff_file(a, b): # Compare the two tree files - (my $short_a = $a) =~ s/[^a-zA-Z0-9.]+/_/g; - (my $short_b = $b) =~ s/[^a-zA-Z0-9.]+/_/g; - my $tmp_a = "/tmp/${$}_${short_a}.a"; - my $tmp_b = "/tmp/${$}_${short_b}.b"; + short_a = re.sub(r'[^a-zA-Z0-9.]+', '_', a) + short_b = re.sub(r'[^a-zA-Z0-9.]+', '_', b) + tmp_a = "/tmp/%s_%s.a" % (os.getpid(), short_a) + tmp_b = "/tmp/%s_%s.b" % (os.getpid(), short_b) - my $vera = version_from($a); - my $verb = version_from($b); - my $verCvt = (($vera < 0x3900 && $verb >= 0x3900) - || ($vera >= 0x3900 && $verb < 0x3900)); + # Version conversion deprecated, but for future... + # vera = version_from(a) + # verb = version_from(b) + # verCvt = ((vera < 0x3900 and verb >= 0x3900) + # or (vera >= 0x3900 and verb < 0x3900)) - filter($a, $tmp_a, $verCvt); - filter($b, $tmp_b, $verCvt); - system("diff -u $tmp_a $tmp_b"); - unlink $tmp_a; - unlink $tmp_b; -} + filterf(a, tmp_a) + filterf(b, tmp_b) + os.system("diff -u " + tmp_a + " " + tmp_b) + os.unlink(tmp_a) + os.unlink(tmp_b) -sub version_from { - my $fn = shift; + +def version_from(filename): # Return dump format - my $f1 = IO::File->new ($fn) or die "%Error: $! $fn,"; - while (defined (my $line=$f1->getline())) { - last if $. > 10; - return hex $1 if $line =~ /\(format (0x[0-9.]+)\)/; - } - return 1.0; -} + with open(filename) as fh: + lineno = 0 + for line in fh: + if lineno > 10: + break + match = re.search(r'format (0x[0-9.]+)', line) + if match: + return hex(match.group(1)) + return 1.0 -sub filter { - my $fn1 = shift; - my $fn2 = shift; - my $verCvt = shift; + +def filterf(fn1, fn2): # Remove hex numbers before diffing - my $f1 = IO::File->new ($fn1) or die "%Error: $! $fn1,"; - my $f2 = IO::File->new ($fn2,"w") or die "%Error: $! $fn2,"; - while (defined (my $line=$f1->getline())) { - same_line: - next if $line =~ / This=/; - $line =~ s/0x[a-f0-9]+/0x/g; - $line =~ s///g; - $line =~ s/{[a-z]*\d+}/{}/g if !$Opt_Lineno; - if ($verCvt) { - next if $line =~ /^ NETLIST/; - if ($line =~ /: ([A-Z]+) /) { - my $type = $1; - next if $type =~ 'DTYPE'; - if ($type eq 'TYPETABLE' || $type eq 'RANGE') { - $line =~ /^(\s+\S+:) /; my $prefix = $1; - while (defined ($line=$f1->getline())) { - next if $line =~ /^\s+[a-z]/; # Table body - next if $line =~ /^${prefix}[0-9]:/; - goto same_line; - } - next; - } - } - } - print $f2 $line; - } - $f1->close; - $f2->close; -} + with open(fn1) as fh1: + with open(fn2, "w") as fh2: + for line in fh1: + if re.search(r' This=', line): + continue + line = re.sub(r'0x[a-f0-9]+', '0x', line) + line = re.sub(r'', '', line) + if not Args.no_lineno: + line = re.sub(r'{[a-z]*\d+}', '{}', line) + fh2.write(line) -#---------------------------------------------------------------------- -sub usage { - pod2usage(-verbose=>2, -exitval=>0, -output=>\*STDOUT); - exit(1); # Unreachable -} +###################################################################### +###################################################################### -sub debug { - $Debug = 1; -} - -sub parameter { - my $param = shift; - if (!defined $Opt_A) { - $Opt_A = $param; - } elsif (!defined $Opt_B) { - $Opt_B = $param; - } else { - die "%Error: Unknown parameter: $param\n"; - } -} - -####################################################################### - -sub run { - # Run a system command, check errors - my $command = shift; - print "\t$command\n"; - system "$command"; - my $status = $?; - ($status == 0) or die "%Error: Command Failed $command, $status, stopped"; -} - -####################################################################### -__END__ - -=pod - -=head1 NAME - -verilator_difftree - Compare two Verilator debugging trees - -=head1 SYNOPSIS - - verilator_difftree .../a/a.tree .../b/a.tree - verilator_difftree .../a .../b - -=head1 DESCRIPTION - -Verilator_difftree is used for debugging Verilator tree output files. It -performs a diff between two files, or all files common between two +parser = argparse.ArgumentParser( + allow_abbrev=False, + formatter_class=argparse.RawDescriptionHelpFormatter, + description="""Compare two Verilator debugging trees""", + epilog= + """Verilator_difftree is used for debugging Verilator tree output files. +It performs a diff between two files, or all files common between two directories, ignoring irrelevant pointer differences. -=head1 ARGUMENTS - -=over 4 - -=item --help - -Displays this message and program version and exits. - -=item --nolineno - -Do not show differences in line numbering. - -=back - -=head1 DISTRIBUTION - -The latest version is available from L. +For documentation see +https://verilator.org/guide/latest/exe_verilator_difftree.html Copyright 2005-2021 by Wilson Snyder. This program is free software; you can redistribute it and/or modify it under the terms of either the GNU Lesser General Public License Version 3 or the Perl Artistic License Version 2.0. -SPDX-License-Identifier: LGPL-3.0-only OR Artistic-2.0 +SPDX-License-Identifier: LGPL-3.0-only OR Artistic-2.0""") -=head1 AUTHORS +parser.add_argument('--debug', + action='store_const', + const=9, + help='enable debug') +parser.add_argument('--no-lineno', + action='store_false', + help='do not show differences in line numbering') +parser.add_argument('filea', help='input file a to diff') +parser.add_argument('fileb', help='input file b to diff') -Wilson Snyder - -=head1 SEE ALSO - -C - -and L for detailed documentation. - -=cut +Args = parser.parse_args() +diff(Args.filea, Args.fileb) ###################################################################### -### Local Variables: -### compile-command: "$V4/bin/verilator_difftree {$V4D,$V4}/test_regress/obj_dir/t_EXAMPLE/V*_03_*.tree" -### End: +# Local Variables: +# compile-command: "./verilator_difftree ../test_regress/t/t_difftree.{a,b}.tree" +# End: diff --git a/bin/verilator_gantt b/bin/verilator_gantt index 8d043670d..17d90e8e4 100755 --- a/bin/verilator_gantt +++ b/bin/verilator_gantt @@ -1,171 +1,162 @@ -#!/usr/bin/env perl -# See copyright, etc in below POD section. +#!/usr/bin/env python3 +# pylint: disable=C0103,C0114,C0116,C0301,R0914,R0912,R0915,W0511,eval-used ###################################################################### -use warnings; -use strict; -use Getopt::Long; -use IO::File; -use Pod::Usage; -use vars qw($Debug); +import argparse +import collections +import math +import re +import statistics +# from pprint import pprint -$Debug = 0; -my $Opt_File; -my $Opt_Time_Per_Char = 0; # rdtsc ticks per char in gantt chart, 0=auto -my $opt_vcd = "profile_threads.vcd"; - -our %Threads; -our %Mtasks; -our %Global; - -autoflush STDOUT 1; -autoflush STDERR 1; -Getopt::Long::config("no_auto_abbrev"); -if (! GetOptions( - "help" => \&usage, - "scale=i" => \$Opt_Time_Per_Char, - "debug" => sub { $Debug = 1; }, - "vcd=s" => \$opt_vcd, - "no-vcd!" => sub { $opt_vcd = undef; }, - "<>" => \¶meter, - )) { - die "%Error: Bad usage, try 'verilator_gantt --help'\n"; +Threads = collections.defaultdict(lambda: {}) +Mtasks = collections.defaultdict(lambda: {}) +Evals = collections.defaultdict(lambda: {}) +EvalLoops = collections.defaultdict(lambda: {}) +Global = { + 'args': {}, + 'cpuinfo': collections.defaultdict(lambda: {}), + 'rdtsc_cycle_time': 0, + 'stats': {} } -$Opt_File = "profile_threads.dat" if !defined $Opt_File; +###################################################################### -process($Opt_File); -write_vcd($opt_vcd) if defined $opt_vcd; -exit(0); -####################################################################### +def process(filename): + read_data(filename) + report() -sub usage { - pod2usage(-verbose=>2, -exitval=>0, -output=>\*STDOUT); - exit(1); # Unreachable -} -sub parameter { - my $param = shift; - if (!defined $Opt_File) { - $Opt_File = $param; - } else { - die "%Error: Unknown parameter: $param\n"; - } -} +def read_data(filename): + with open(filename) as fh: + re_prof = re.compile( + r'^VLPROF mtask\s(\d+)\sstart\s(\d+)\selapsed\s(\d+)\spredict_start\s(\d+)\spredict_cost\s(\d+)\scpu\s(\d+)\son thread (\d+)' + ) + re_eval = re.compile(r'^VLPROF eval\sstart\s(\d+)\selapsed\s(\d+)') + re_loop = re.compile( + r'^VLPROF eval_loop\sstart\s(\d+)\selapsed\s(\d+)') + re_arg1 = re.compile(r'VLPROF arg\s+(\S+)\+([0-9.]*)\s*') + re_arg2 = re.compile(r'VLPROF arg\s+(\S+)\s+([0-9.]*)\s*$') + re_stat = re.compile(r'VLPROF stat\s+(\S+)\s+([0-9.]+)') + re_time = re.compile(r'rdtsc time = (\d+) ticks') + re_proc_cpu = re.compile(r'VLPROFPROC processor\s*:\s*(\d+)\s*$') + re_proc_dat = re.compile(r'VLPROFPROC ([a-z_ ]+)\s*:\s*(.*)$') + cpu = None -####################################################################### + for line in fh: + if re_prof.match(line): + match = re_prof.match(line) + mtask = int(match.group(1)) + start = int(match.group(2)) + elapsed_time = int(match.group(3)) + end = start + elapsed_time + predict_start = int(match.group(4)) + predict_cost = int(match.group(5)) + cpu = int(match.group(6)) + thread = int(match.group(7)) + if start not in Threads[thread]: + Threads[thread][start] = {} + Threads[thread][start]['mtask'] = mtask + Threads[thread][start]['end'] = end + Threads[thread][start]['cpu'] = cpu + Threads[thread][start]['predict_start'] = predict_start + Threads[thread][start]['predict_cost'] = predict_cost -sub process { - my $filename = shift; + if 'elapsed' not in Mtasks[mtask]: + Mtasks[mtask] = {'end': 0, 'elapsed': 0} + Mtasks[mtask]['thread'] = thread + Mtasks[mtask]['elapsed'] += elapsed_time + Mtasks[mtask]['predict_start'] = predict_start + Mtasks[mtask]['predict_cost'] = predict_cost + Mtasks[mtask]['end'] = max(Mtasks[mtask]['end'], end) + elif re_eval.match(line): + match = re_eval.match(line) + start = int(match.group(1)) + elapsed_time = int(match.group(2)) + Evals[start]['start'] = start + Evals[start]['end'] = start + elapsed_time + elif re_loop.match(line): + match = re_loop.match(line) + start = int(match.group(1)) + elapsed_time = int(match.group(2)) + EvalLoops[start]['start'] = start + EvalLoops[start]['end'] = start + elapsed_time + elif re.match(r'^VLPROFTHREAD', line): + None # pylint: disable=pointless-statement + elif re_arg1.match(line): + match = re_arg1.match(line) + Global['args'][match.group(1)] = match.group(2) + elif re_arg2.match(line): + match = re_arg2.match(line) + Global['args'][match.group(1)] = match.group(2) + elif re_stat.match(line): + match = re_stat.match(line) + Global['stats'][match.group(1)] = match.group(2) + elif re_proc_cpu.match(line): + match = re_proc_cpu.match(line) + cpu = int(match.group(1)) + elif cpu and re_proc_dat.match(line): + match = re_proc_dat.match(line) + term = match.group(1) + value = match.group(2) + term = re.sub(r'\s+$', '', term) + term = re.sub(r'\s+', '_', term) + value = re.sub(r'\s+$', '', value) + Global['cpuinfo'][cpu][term] = value + elif re.match(r'^#', line): + None # pylint: disable=pointless-statement + elif Args.debug: + print("-Unk: %s" % line) + # TODO -- this is parsing text printed by a client. + # Really, verilator proper should generate this + # if it's useful... + if re_time.match(line): + Global['rdtsc_cycle_time'] = re_time.group(1) - read_data($filename); - read_cpuinfo(); - report(); -} -####################################################################### +def re_match_result(regexp, line, result_to): + result_to = re.match(regexp, line) + return result_to -sub read_data { - my $filename = shift; - %Global = (rdtsc_cycle_time => 0); +###################################################################### - my $fh = IO::File->new("<$filename") or die "%Error: $! $filename,"; - while (my $line = $fh->getline) { - if ($line =~ m/VLPROF mtask\s(\d+)\sstart\s(\d+)\send\s(\d+)\selapsed\s(\d+)\spredict_time\s(\d+)\scpu\s(\d+)\son thread (\d+)/) { - my $mtask = $1; - my $start = $2; - my $end = $3; - my $elapsed_time = $4; - my $predict_time = $5; - my $cpu = $6; - my $thread = $7; - $Threads{$thread}{$start}{mtask} = $mtask; - $Threads{$thread}{$start}{end} = $end; - $Threads{$thread}{$start}{cpu} = $cpu; - if (!exists $Mtasks{$mtask}{elapsed}) { - $Mtasks{$mtask}{elapsed} = 0; - } - $Mtasks{$mtask}{elapsed} += $elapsed_time; - $Mtasks{$mtask}{predict} = $predict_time; - $Mtasks{$mtask}{end} = max($Mtasks{$mtask}{end}, $end); - } - elsif ($line =~ /^VLPROFTHREAD/) {} - elsif ($line =~ m/VLPROF arg\s+(\S+)\+([0-9.])\s*$/ - || $line =~ m/VLPROF arg\s+(\S+)\s+([0-9.])\s*$/) { - $Global{args}{$1} = $2; - } - elsif ($line =~ m/VLPROF stat\s+(\S+)\s+([0-9.]+)/) { - $Global{stats}{$1} = $2; - } - elsif ($line =~ /^#/) {} - elsif ($Debug) { - chomp $line; - print "Unk: $line\n"; - } - # TODO -- this is parsing text printed by a client. - # Really, verilator proper should generate this - # if it's useful... - if ($line =~ m/rdtsc time = (\d+) ticks/) { - $Global{rdtsc_cycle_time} = $1; - } - } -} +def report(): + print("Verilator Gantt report") -sub read_cpuinfo { - my $filename = "/proc/cpuinfo"; - my $fh = IO::File->new("<$filename") or return; - my $cpu; - while (my $line = $fh->getline) { - chomp $line; - if ($line =~ m/^processor\s*:\s*(\d+)\s*$/) { - $cpu = $1; - } - if ($cpu && $line =~ m/^([a-z_ ]+)\s*:\s*(.*)$/) { - my ($term, $value) = ($1, $2); - $term =~ s/\s+$//; - $term =~ s/\s+/_/; - $value =~ s/\s+$//; - $Global{cpuinfo}{$cpu}{$term} = $value; - } - } -} + print("\nArgument settings:") + for arg in sorted(Global['args'].keys()): + plus = "+" if re.match(r'^\+', arg) else " " + print(" %s%s%s" % (arg, plus, Global['args'][arg])) -####################################################################### - -sub report { - print "Verilator Gantt report\n"; - - print "\nArgument settings:\n"; - foreach my $arg (sort keys %{$Global{args}}) { - my $plus = ($arg =~ /^\+/) ? "+" : " "; - printf " %s%s%d\n", $arg, $plus, $Global{args}{$arg}; - } - - my $nthreads = scalar keys %Threads; - $Global{cpus} = {}; - foreach my $thread (keys %Threads) { + nthreads = len(Threads) + Global['cpus'] = {} + for thread in Threads: # Make potentially multiple characters per column - foreach my $start (keys %{$Threads{$thread}}) { - my $cpu = $Threads{$thread}{$start}{cpu}; - my $elapsed = $Threads{$thread}{$start}{end} - $start; - $Global{cpus}{$cpu}{cpu_time} += $elapsed; - } - } + for start in Threads[thread]: + cpu = Threads[thread][start]['cpu'] + elapsed = Threads[thread][start]['end'] - start + if cpu not in Global['cpus']: + Global['cpus'][cpu] = {'cpu_time': 0} + Global['cpus'][cpu]['cpu_time'] += elapsed - my $mt_mtask_time = 0; - my $long_mtask_time = 0; - my $last_end = 0; - foreach my $mtask (keys %Mtasks) { - $mt_mtask_time += $Mtasks{$mtask}{elapsed}; - $last_end = max($last_end, $Mtasks{$mtask}{end}); - $long_mtask_time = max($long_mtask_time, $Mtasks{$mtask}{elapsed}); - } - $Global{last_end} = $last_end; - - report_graph(); + measured_mt_mtask_time = 0 + predict_mt_mtask_time = 0 + long_mtask_time = 0 + measured_last_end = 0 + predict_last_end = 0 + for mtask in Mtasks: + measured_mt_mtask_time += Mtasks[mtask]['elapsed'] + predict_mt_mtask_time += Mtasks[mtask]['predict_cost'] + measured_last_end = max(measured_last_end, Mtasks[mtask]['end']) + predict_last_end = max( + predict_last_end, + Mtasks[mtask]['predict_start'] + Mtasks[mtask]['predict_cost']) + long_mtask_time = max(long_mtask_time, Mtasks[mtask]['elapsed']) + Global['measured_last_end'] = measured_last_end + Global['predict_last_end'] = predict_last_end # If we know cycle time in the same (rdtsc) units, # this will give us an actual utilization number, @@ -175,402 +166,328 @@ sub report { # serial mode, to estimate the overhead of data sharing, # which will show up in the total elapsed time. (Overhead # of synchronization and scheduling should not.) - print "\nAnalysis:\n"; - printf " Total threads = %d\n", $nthreads; - printf " Total mtasks = %d\n", scalar(keys %Mtasks); - my $ncpus = scalar(keys %{$Global{cpus}}); - printf " Total cpus used = %d\n", $ncpus; - printf " Total yields = %d\n", $Global{stats}{yields}; - printf " Total eval time = %d rdtsc ticks\n", $Global{last_end}; - printf " Longest mtask time = %d rdtsc ticks\n", $long_mtask_time; - printf " All-thread mtask time = %d rdtsc ticks\n", $mt_mtask_time; - my $long_efficiency = $long_mtask_time/($Global{last_end} || 1); - printf " Longest-thread efficiency = %0.1f%%\n", $long_efficiency*100; - my $mt_efficiency = $mt_mtask_time/($Global{last_end}*$nthreads || 1); - printf " All-thread efficiency = %0.1f%%\n", $mt_efficiency*100; - printf " All-thread speedup = %0.1f\n", $mt_efficiency*$nthreads; - if ($Global{rdtsc_cycle_time} > 0) { - my $ut = $mt_mtask_time / $Global{rdtsc_cycle_time}; - print "tot_mtask_cpu=$mt_mtask_time cyc=$Global{rdtsc_cycle_time} ut=$ut\n"; - } + print("\nAnalysis:") + print(" Total threads = %d" % nthreads) + print(" Total mtasks = %d" % len(Mtasks)) + ncpus = len(Global['cpus']) + print(" Total cpus used = %d" % ncpus) + print(" Total yields = %d" % int(Global['stats']['yields'])) + print(" Total evals = %d" % len(Evals)) + print(" Total eval loops = %d" % len(EvalLoops)) + print(" Total eval time = %d rdtsc ticks" % + Global['measured_last_end']) + print(" Longest mtask time = %d rdtsc ticks" % long_mtask_time) + print(" All-thread mtask time = %d rdtsc ticks" % + measured_mt_mtask_time) + long_efficiency = long_mtask_time / (Global.get('measured_last_end', 1) + or 1) + print(" Longest-thread efficiency = %0.1f%%" % (long_efficiency * 100.0)) + mt_efficiency = measured_mt_mtask_time / ( + Global.get('measured_last_end', 1) * nthreads or 1) + print(" All-thread efficiency = %0.1f%%" % (mt_efficiency * 100.0)) + print(" All-thread speedup = %0.1f" % (mt_efficiency * nthreads)) + if Global['rdtsc_cycle_time'] > 0: + ut = measured_mt_mtask_time / Global['rdtsc_cycle_time'] + print("tot_mtask_cpu=" + measured_mt_mtask_time + " cyc=" + + Global['rdtsc_cycle_time'] + " ut=" + ut) - my @p2e_ratios; - my $min_p2e = 1000000; - my $min_mtask; - my $max_p2e = -1000000; - my $max_mtask; - foreach my $mtask (sort keys %Mtasks) { - if ($Mtasks{$mtask}{elapsed} > 0) { - if ($Mtasks{$mtask}{predict} == 0) { - $Mtasks{$mtask}{predict} = 1; # don't log(0) below - } - my $p2e_ratio = log( $Mtasks{$mtask}{predict} / $Mtasks{$mtask}{elapsed} ); - #print "log(p2e $mtask) = $p2e_ratio (predict $Mtasks{$mtask}{predict}, elapsed $Mtasks{$mtask}{elapsed})\n"; - push @p2e_ratios, $p2e_ratio; + predict_mt_efficiency = predict_mt_mtask_time / ( + Global.get('predict_last_end', 1) * nthreads or 1) + print("\nPrediction (what Verilator used for scheduling):") + print(" All-thread efficiency = %0.1f%%" % + (predict_mt_efficiency * 100.0)) + print(" All-thread speedup = %0.1f" % + (predict_mt_efficiency * nthreads)) - if ($p2e_ratio > $max_p2e) { - $max_p2e = $p2e_ratio; - $max_mtask = $mtask; - } - if ($p2e_ratio < $min_p2e) { - $min_p2e = $p2e_ratio; - $min_mtask = $mtask; - } + p2e_ratios = [] + min_p2e = 1000000 + min_mtask = None + max_p2e = -1000000 + max_mtask = None + + for mtask in sorted(Mtasks.keys()): + if Mtasks[mtask]['elapsed'] > 0: + if Mtasks[mtask]['predict_cost'] == 0: + Mtasks[mtask]['predict_cost'] = 1 # don't log(0) below + p2e_ratio = math.log(Mtasks[mtask]['predict_cost'] / + Mtasks[mtask]['elapsed']) + p2e_ratios.append(p2e_ratio) + + if p2e_ratio > max_p2e: + max_p2e = p2e_ratio + max_mtask = mtask + if p2e_ratio < min_p2e: + min_p2e = p2e_ratio + min_mtask = mtask + + print("\nStatistics:") + print(" min log(p2e) = %0.3f" % min_p2e, end="") + print(" from mtask %d (predict %d," % + (min_mtask, Mtasks[min_mtask]['predict_cost']), + end="") + print(" elapsed %d)" % Mtasks[min_mtask]['elapsed']) + print(" max log(p2e) = %0.3f" % max_p2e, end="") + print(" from mtask %d (predict %d," % + (max_mtask, Mtasks[max_mtask]['predict_cost']), + end="") + print(" elapsed %d)" % Mtasks[max_mtask]['elapsed']) + + stddev = statistics.pstdev(p2e_ratios) + mean = statistics.mean(p2e_ratios) + print(" mean = %0.3f" % mean) + print(" stddev = %0.3f" % stddev) + print(" e ^ stddev = %0.3f" % math.exp(stddev)) + + report_cpus() + + if nthreads > ncpus: + print() + print("%%Warning: There were fewer CPUs (%d) then threads (%d)." % + (ncpus, nthreads)) + print(" : See docs on use of numactl.") + else: + if 'cpu_socket_cores_warning' in Global: + print() + print( + "%Warning: Multiple threads scheduled on same hyperthreaded core." + ) + print(" : See docs on use of numactl.") + if 'cpu_sockets_warning' in Global: + print() + print("%Warning: Threads scheduled on multiple sockets.") + print(" : See docs on use of numactl.") + print() + + +def report_cpus(): + print("\nCPUs:") + + Global['cpu_sockets'] = collections.defaultdict(lambda: 0) + Global['cpu_socket_cores'] = collections.defaultdict(lambda: 0) + + for cpu in sorted(Global['cpus'].keys()): + print(" cpu %d: " % cpu, end='') + print("cpu_time=%d" % Global['cpus'][cpu]['cpu_time'], end='') + + socket = None + if cpu in Global['cpuinfo']: + cpuinfo = Global['cpuinfo'][cpu] + if 'physical_id' in cpuinfo and 'core_id' in cpuinfo: + socket = int(cpuinfo['physical_id']) + Global['cpu_sockets'][socket] += 1 + print(" socket=%d" % socket, end='') + + core = int(cpuinfo['core_id']) + Global['cpu_socket_cores'][str(socket) + "__" + str(core)] += 1 + print(" core=%d" % core, end='') + + if 'model_name' in cpuinfo: + model = cpuinfo['model_name'] + print(" %s" % model, end='') + print() + + if len(Global['cpu_sockets']) > 1: + Global['cpu_sockets_warning'] = True + for scn in Global['cpu_socket_cores'].values(): + if scn > 1: + Global['cpu_socket_cores_warning'] = True + + +###################################################################### + + +def write_vcd(filename): + print("Writing %s" % filename) + with open(filename, "w") as fh: + vcd = { + 'values': + collections.defaultdict(lambda: {}), # {