get_abi: improve message output and fix a regression
cover get_abi: improve message output and fix a regression
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#u
I'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
scripts/get_abi.pl undefined 2>logs
The "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
-
Patch 3 is just a small fix for an issue introduced by an earlier change at the script (unrelated to the other two patches).
Mauro Carvalho Chehab (3):
scripts:: use STDERR for search-string and show-hints
scripts: get_abi.pl: show progress
ABI: evm: place a second what at the next line
Documentation/ABI/testing/evm | 3 +- scripts/get_abi.pl | 165 ++++++++++++++++++++++------------ 2 files changed, 111 insertions(+), 57 deletions(-)
Signature · 1 line
2.31.1
PATCH 1/3 scripts: get_abi.pl: use STDERR for search-string and show-hints
On undefined checks, use STDOUT only for the not found entries.
All other data (search-string and show-hints) is printed at STDERR.
---
To mailbombing on a large number of people, only mailing lists were C/C on the cover. See [PATCH 0/3] at: https://lore.kernel.org/all/[email protected]/
scripts/get_abi.pl | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-)
scripts/get_abi.pl +7 -7
@@ -728,9 +728,9 @@ sub check_undefined_symbols { for (my $i = 0; $i < @names; $i++) { if ($found_string && $hint) { if (!$i) { - print "--> $names[$i]\n"; + print STDERR "--> $names[$i]\n"; } else { - print " $names[$i]\n"; + print STDERR " $names[$i]\n"; } } foreach my $re (@expr) {
@@ -760,17 +760,17 @@ sub check_undefined_symbols { } next if ($exact); + print "$file not found.\n" if (!$search_string || $found_string); + if ($hint && (!$search_string || $found_string)) { my $what = $leaf{$leave}->{what}; $what =~ s/\xac/\n\t/g; if ($leave ne "others") { - print " more likely regexes:\n\t$what\n"; + print STDERR " more likely regexes:\n\t$what\n"; } else { - print " tested regexes:\n\t$what\n"; + print STDERR " tested regexes:\n\t$what\n"; } - next; } - print "$file not found.\n" if (!$search_string || $found_string); } }
@@ -852,7 +852,7 @@ sub undefined_symbols { } } if ($search_string && $added) { - print "What: $what\n" if ($what =~ m#$search_string#); + print STDERR "What: $what\n" if ($what =~ m#$search_string#); } }
Signature · 1 line
2.31.1
PATCH 2/3 scripts: get_abi.pl: show progress
In reply to Mauro Carvalho ChehabAs parsing the sysfs entries can take a long time, add progress information.
The progress logic will update the stats on every second, or on 1% steps of the progress.
When STDERR is a console, it will use a single line, using a VT-100 command to erase the line before rewriting it. Otherwise, it will put one message on a separate line. That would help to identify what parts of sysfs checking that it is taking more time to process.
---
To mailbombing on a large number of people, only mailing lists were C/C on the cover. See [PATCH 0/3] at: https://lore.kernel.org/all/[email protected]/
scripts/get_abi.pl | 163 ++++++++++++++++++++++++++++++--------------- 1 file changed, 108 insertions(+), 55 deletions(-)
scripts/get_abi.pl +108 -55
@@ -9,6 +9,7 @@ use utf8; use Pod::Usage qw(pod2usage); use Getopt::Long; use File::Find; +use IO::Handle; use Fcntl ':mode'; use Cwd 'abs_path'; use Data::Dumper;
@@ -702,87 +703,137 @@ sub get_leave($) return $leave; } -sub check_undefined_symbols { - foreach my $file_ref (sort @files) { - my @names = @{$$file_ref{"__name"}}; - my $file = $names[0]; +my @not_found; - my $exact = 0; - my $found_string; +sub check_file($$) +{ + my $file_ref = shift; + my $names_ref = shift; + my @names = @{$names_ref}; + my $file = $names[0]; - my $leave = get_leave($file); - if (!defined($leaf{$leave})) { - $leave = "others"; + my $found_string; + + my $leave = get_leave($file); + if (!defined($leaf{$leave})) { + $leave = "others"; + } + my @expr = @{$leaf{$leave}->{expr}}; + die ("\rmissing rules for $leave") if (!defined($leaf{$leave})); + + my $path = $file; + $path =~ s,(.*/).*,$1,; + + if ($search_string) { + return if (!($file =~ m#$search_string#)); + $found_string = 1; + } + + for (my $i = 0; $i < @names; $i++) { + if ($found_string && $hint) { + if (!$i) { + print STDERR "--> $names[$i]\n"; + } else { + print STDERR " $names[$i]\n"; + } + } + foreach my $re (@expr) { + print STDERR "$names[$i] =~ /^$re\$/\n" if ($debug && $dbg_undefined); + if ($names[$i] =~ $re) { + return; + } } + } + + if ($leave ne "others") { my @expr = @{$leaf{$leave}->{expr}}; - die ("missing rules for $leave") if (!defined($leaf{$leave})); - - my $path = $file; - $path =~ s,(.*/).*,$1,; - - if ($search_string) { - next if (!($file =~ m#$search_string#)); - $found_string = 1; - } - for (my $i = 0; $i < @names; $i++) { - if ($found_string && $hint) { - if (!$i) { - print STDERR "--> $names[$i]\n"; - } else { - print STDERR " $names[$i]\n"; - } - } foreach my $re (@expr) { - print "$names[$i] =~ /^$re\$/\n" if ($debug && $dbg_undefined); + print STDERR "$names[$i] =~ /^$re\$/\n" if ($debug && $dbg_undefined); if ($names[$i] =~ $re) { - $exact = 1; - last; + return; } } - last if ($exact); } - next if ($exact); + } + push @not_found, $file if (!$search_string || $found_string); + + if ($hint && (!$search_string || $found_string)) { + my $what = $leaf{$leave}->{what}; + $what =~ s/\xac/\n\t/g; if ($leave ne "others") { - my @expr = @{$leaf{$leave}->{expr}}; - for (my $i = 0; $i < @names; $i++) { - foreach my $re (@expr) { - print "$names[$i] =~ /^$re\$/\n" if ($debug && $dbg_undefined); - if ($names[$i] =~ $re) { - $exact = 1; - last; - } - } - last if ($exact); - } - last if ($exact); + print STDERR "\r more likely regexes:\n\t$what\n"; + } else { + print STDERR "\r tested regexes:\n\t$what\n"; } - next if ($exact); - - print "$file not found.\n" if (!$search_string || $found_string); - - if ($hint && (!$search_string || $found_string)) { - my $what = $leaf{$leave}->{what}; - $what =~ s/\xac/\n\t/g; - if ($leave ne "others") { - print STDERR " more likely regexes:\n\t$what\n"; - } else { - print STDERR " tested regexes:\n\t$what\n"; - } + } +} + +sub check_undefined_symbols { + my $num_files = scalar @files; + my $next_i = 0; + my $start_time = times; + + my $last_time = $start_time; + + # When either debug or hint is enabled, there's no sense showing + # progress, as the progress will be overriden. + if ($hint || ($debug && $dbg_undefined)) { + $next_i = $num_files; + } + + my $is_console; + $is_console = 1 if (-t STDERR); + + for (my $i = 0; $i < $num_files; $i++) { + my $file_ref = $files[$i]; + my @names = @{$$file_ref{"__name"}}; + + check_file($file_ref, \@names); + + my $cur_time = times; + + if ($i == $next_i || $cur_time > $last_time + 1) { + my $percent = $i * 100 / $num_files; + + my $tm = $cur_time - $start_time; + my $time = sprintf "%d:%02d", int($tm), 60 * ($tm - int($tm)); + + printf STDERR "\33[2K\r", if ($is_console); + printf STDERR "%s: processing sysfs files... %i%%: $names[0]", $time, $percent; + printf STDERR "\n", if (!$is_console); + STDERR->flush(); + + $next_i = int (($percent + 1) * $num_files / 100); + $last_time = $cur_time; } } + + my $cur_time = times; + my $tm = $cur_time - $start_time; + my $time = sprintf "%d:%02d", int($tm), 60 * ($tm - int($tm)); + + printf STDERR "\33[2K\r", if ($is_console); + printf STDERR "%s: processing sysfs files... done\n", $time; + + foreach my $file (@not_found) { + print "$file not found.\n"; + } } sub undefined_symbols { + print STDERR "Reading $sysfs_prefix directory contents..."; find({ wanted =>\&parse_existing_sysfs, preprocess =>\&dont_parse_special_attributes, no_chdir => 1 }, $sysfs_prefix); + print STDERR "done.\n"; $leaf{"others"}->{what} = ""; + print STDERR "Converting ABI What fields into regexes..."; foreach my $w (sort keys %data) { foreach my $what (split /\xac/,$w) { next if (!($what =~ m/^$sysfs_prefix/));
@@ -871,6 +922,8 @@ sub undefined_symbols { my $abs_file = $aliases{$link}; graph_add_link($abs_file, $link); } + print STDERR "done.\n"; + check_undefined_symbols; }
Signature · 1 line
2.31.1
PATCH 3/3 ABI: evm: place a second what at the next line
In reply to Mauro Carvalho ChehabOriginally, get_abi.pl was using spaces to separate What: parameters, but there are several references that declare things like:
/sys/class/powercap/.../<power zone>/enabled
So, the logic was changes in order to properly address it.
That broke the second What added by
Changeset 18e49b304633 ("ABI: security: fix location for evm and ima_policy").
As the only file that defines multiple What: at the same line is this file, let's move the second What: to a separate line.
---
To mailbombing on a large number of people, only mailing lists were C/C on the cover. See [PATCH 0/3] at: https://lore.kernel.org/all/[email protected]/
Documentation/ABI/testing/evm | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-)
Documentation/ABI/testing/evm +2 -1
@@ -1,4 +1,5 @@ -What: /sys/kernel/security/evm /sys/kernel/security/*/evm +What: /sys/kernel/security/evm +What: /sys/kernel/security/*/evm Date: March 2011 Contact: Mimi Zohar <[email protected]> Description:
Signature · 1 line
2.31.1
Quoted 12 lines · Mauro Carvalho Chehab
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
Quoted 7 lines
If you run it on your big server with:
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking, I got the following debug output that seems to pinpoint the problem file.
The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap
and here's some debugging output for the regex it needs to search for this:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/
And sometimes this thing finishes in 20 seconds, and others, many many minutes. It's not deterministic at all, which is odd. Is the sysfs tree being sorted so that this should always have the same search order?
Anyway, I've applied this series as well, this helps in finding the problems :)
Note, I can provide an off-list tarball of /sys/ if that would help in debugging anything on your end.
thanks,
greg k-h
Em Tue, 28 Sep 2021 13:04:22 +0200
Greg Kroah-Hartman <[email protected]> escreveu:
Quoted 15 lines · Mauro Carvalho Chehab
Quoted 14 lines
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
Quoted 8 lines
Quoted 5 lines
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking,
Feel free to modify the script and add such debug/tweaks if you find it useful.
Quoted 9 lines
I got the following
debug output that seems to pinpoint the problem file.The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/capand here's some debugging output for the regex it needs to search for this:
Quoted 12 lines
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/
Hmm... interesting. Perhaps the problem is on regexes like this:
/^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/
Which actually represents this What:
/sys/devices/pciXXXX:XX/0000:XX:XX.X/dma/dma<n>chan<n>/quickdata/cap
The script could have done a better job escaping "." character on it (but that is not too trivial) and grouping altogether ".*" repetitions, although, in this specific case, probably the best regex would be, instead:
/sys/devices/pci[\da-f:\.]+/dma/dma\d+chan\d+/quickdata/cap
One possible long-term solution would be to directly use regexes directly on "What" fields inside Documentation/ABI, but on some parts this would require some changes, like, for instance:
/sys/bus/usb/devices/<busnum>-<devnum>:<config num>.<interface num>/<hid-bus>:<vendor-id>:<product-id>.<num>/kone/roccatkone<minor>/weight
Ok, we could likely use capture groups like:
(?<NAME>pattern)
but IMO that would make it a lot harder to be understood by humans.
Quoted 3 lines
And sometimes this thing finishes in 20 seconds, and others, many many minutes. It's not deterministic at all, which is odd. Is the sysfs tree being sorted so that this should always have the same search order?
No, because it uses a lot of hashes in order to speed it up. Yet, it shouldn't be hard - nor it would significantly affect the processing time - to make it more deterministic. See the enclosed path.
Quoted 2 lines
Anyway, I've applied this series as well, this helps in finding the problems :)
Thanks!
Quoted 2 lines
Note, I can provide an off-list tarball of
/sys/if that would help in debugging anything on your end.
Yeah, that can help. Feel free to send it to me.
Btw, I just got an arm64 server with 128 CPUs for testing. I'm trying to allocate also a big x86 server here, but I'm not sure if it is AMD or Intel.
Thanks,
Mauro
[PATCH] scripts: get_abi.pl: make undefined search more deterministic
Sort keys on hashes during undefined search, in order to make the script more deterministic.
scripts/get_abi.pl +5 -3
@@ -775,6 +775,8 @@ sub check_undefined_symbols { my $next_i = 0; my $start_time = times; + @files = sort @files; + my $last_time = $start_time; # When either debug or hint is enabled, there's no sense showing
@@ -909,16 +911,16 @@ sub undefined_symbols { } } # Compile regexes - foreach my $l (keys %leaf) { + foreach my $l (sort keys %leaf) { my @expr; - foreach my $w(split /\xac/, $leaf{$l}->{what}) { + foreach my $w(sort split /\xac/, $leaf{$l}->{what}) { push @expr, qr /^$w$/; } $leaf{$l}->{expr} = \@expr; } # Take links into account - foreach my $link (keys %aliases) { + foreach my $link (sort keys %aliases) { my $abs_file = $aliases{$link}; graph_add_link($abs_file, $link); }
Em Tue, 28 Sep 2021 14:27:39 +0200
Mauro Carvalho Chehab <[email protected]> escreveu:
Quoted 33 lines
Em Tue, 28 Sep 2021 13:04:22 +0200
Greg Kroah-Hartman <[email protected]> escreveu:Quoted 15 lines · Mauro Carvalho Chehab
Quoted 14 lines
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
Quoted 8 lines
Quoted 5 lines
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking,
Feel free to modify the script and add such debug/tweaks if you find it useful.
Quoted 3 lines
I got the following
debug output that seems to pinpoint the problem file.
Quoted 7 lines
Quoted 3 lines
The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/capBtw, I just got an arm64 server with 128 CPUs for testing. I'm trying to allocate also a big x86 server here, but I'm not sure if it is AMD or Intel.
Some tests on a Gigabyte R182-Z91-00 server, equipped with AMD EPYC 7352 24-Core Processors (total 96 threads):
$ find /sys |wc -l 233981
$ time ./scripts/get_abi.pl undefined >undefined 2>logs
real 0m38.917s user 0m34.554s sys 0m4.292s
PS.: this machine doesn't have anything at /sys/class/iommu.
On a Huawei TaiShan 200 (Model 2280) with 128 ARM cores:
$ find /sys |wc -l 99362 $ time ./scripts/get_abi.pl undefined >undefined 2>logs
real 0m29.311s user 0m26.173s sys 0m3.061s
Both machines are using Perl 5.26.
Thanks,
Mauro
Quoted 64 lines · Mauro Carvalho Chehab
Em Tue, 28 Sep 2021 14:27:39 +0200
Mauro Carvalho Chehab <[email protected]> escreveu:Quoted 33 lines
Em Tue, 28 Sep 2021 13:04:22 +0200
Greg Kroah-Hartman <[email protected]> escreveu:Quoted 15 lines · Mauro Carvalho Chehab
Quoted 14 lines
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
Quoted 8 lines
Quoted 5 lines
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking,
Feel free to modify the script and add such debug/tweaks if you find it useful.
Quoted 3 lines
I got the following
debug output that seems to pinpoint the problem file.Quoted 7 lines
Quoted 3 lines
The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/capBtw, I just got an arm64 server with 128 CPUs for testing. I'm trying to allocate also a big x86 server here, but I'm not sure if it is AMD or Intel.
Some tests on a Gigabyte R182-Z91-00 server, equipped with AMD EPYC 7352 24-Core Processors (total 96 threads):
$ find /sys |wc -l 233981$ time ./scripts/get_abi.pl undefined >undefined 2>logsreal 0m38.917s user 0m34.554s sys 0m4.292sPS.: this machine doesn't have anything at
/sys/class/iommu.On a Huawei TaiShan 200 (Model 2280) with 128 ARM cores:
$ find /sys |wc -l 99362 $ time ./scripts/get_abi.pl undefined >undefined 2>logs
Quoted 5 lines
real 0m29.311s user 0m26.173s sys 0m3.061sBoth machines are using Perl 5.26.
Try it with your sorting patch, that fixed it for me and now it runs in 10 seconds.
crazy.
Quoted 79 lines · Mauro Carvalho Chehab
Em Tue, 28 Sep 2021 13:04:22 +0200
Greg Kroah-Hartman <[email protected]> escreveu:Quoted 15 lines · Mauro Carvalho Chehab
Quoted 14 lines
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
Quoted 8 lines
Quoted 5 lines
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking,
Feel free to modify the script and add such debug/tweaks if you find it useful.
Quoted 9 lines
I got the following
debug output that seems to pinpoint the problem file.The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/capand here's some debugging output for the regex it needs to search for this:
Quoted 12 lines
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/
Hmm... interesting. Perhaps the problem is on regexes like this:
/^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/Which actually represents this What:
/sys/devices/pciXXXX:XX/0000:XX:XX.X/dma/dma<n>chan<n>/quickdata/capThe script could have done a better job escaping "." character on it (but that is not too trivial) and grouping altogether ".*" repetitions, although, in this specific case, probably the best regex would be, instead:
/sys/devices/pci[\da-f:\.]+/dma/dma\d+chan\d+/quickdata/capOne possible long-term solution would be to directly use regexes directly on "What" fields inside
Documentation/ABI, but on some parts this would require some changes, like, for instance:/sys/bus/usb/devices/<busnum>-<devnum>:<config num>.<interface num>/<hid-bus>:<vendor-id>:<product-id>.<num>/kone/roccatkone<minor>/weightOk, we could likely use capture groups like:
(?<NAME>pattern)but IMO that would make it a lot harder to be understood by humans.
Quoted 7 lines
Quoted 3 lines
And sometimes this thing finishes in 20 seconds, and others, many many minutes. It's not deterministic at all, which is odd. Is the sysfs tree being sorted so that this should always have the same search order?
No, because it uses a lot of hashes in order to speed it up. Yet, it shouldn't be hard - nor it would significantly affect the processing time - to make it more deterministic. See the enclosed path.
That patch solved everything.
It now only takes 10 seconds. Every time. Without the patch, it feels hung for some reason.
Care to turn that into a patch that I can take?
Quoted 5 lines
Quoted 2 lines
Anyway, I've applied this series as well, this helps in finding the problems :)
Thanks!
Quoted 8 lines
Quoted 2 lines
Note, I can provide an off-list tarball of
/sys/if that would help in debugging anything on your end.Yeah, that can help. Feel free to send it to me.
Btw, I just got an arm64 server with 128 CPUs for testing. I'm trying to allocate also a big x86 server here, but I'm not sure if it is AMD or Intel.
This is on perl 5.34 here.
thanks,
greg k-h
PATCH 1/1 scripts: get_abi.pl: make undefined search more deterministic
Sort keys on hashes during undefined search, in order to make the script more deterministic.
--- scripts/get_abi.pl | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-)
scripts/get_abi.pl +5 -3
@@ -775,6 +775,8 @@ sub check_undefined_symbols { my $next_i = 0; my $start_time = times; + @files = sort @files; + my $last_time = $start_time; # When either debug or hint is enabled, there's no sense showing
@@ -909,16 +911,16 @@ sub undefined_symbols { } } # Compile regexes - foreach my $l (keys %leaf) { + foreach my $l (sort keys %leaf) { my @expr; - foreach my $w(split /\xac/, $leaf{$l}->{what}) { + foreach my $w(sort split /\xac/, $leaf{$l}->{what}) { push @expr, qr /^$w$/; } $leaf{$l}->{expr} = \@expr; } # Take links into account - foreach my $link (keys %aliases) { + foreach my $link (sort keys %aliases) { my $abs_file = $aliases{$link}; graph_add_link($abs_file, $link); }
Signature · 1 line
2.31.1
Re: [PATCH] scripts: get_abi.pl: make undefined search more deterministic
Quoted 44 lines · Mauro Carvalho Chehab
Sort keys on hashes during undefined search, in order to make the script more deterministic.
Signed-off-by Mauro Carvalho Chehab <[email protected]>--- scripts/get_abi.pl | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-)scripts/get_abi.pl +5
-3@@ -775,6 +775,8 @@ sub check_undefined_symbols { my $next_i = 0; my $start_time = times; + @files = sort @files; + my $last_time = $start_time; # When either debug or hint is enabled, there's no sense showing@@ -909,16 +911,16 @@ sub undefined_symbols { } } # Compile regexes - foreach my $l (keys %leaf) { + foreach my $l (sort keys %leaf) { my @expr; - foreach my $w(split /\xac/, $leaf{$l}->{what}) { + foreach my $w(sort split /\xac/, $leaf{$l}->{what}) { push @expr, qr /^$w$/; } $leaf{$l}->{expr} = \@expr; } # Take links into account - foreach my $link (keys %aliases) { + foreach my $link (sort keys %aliases) { my $abs_file = $aliases{$link}; graph_add_link($abs_file, $link); }Signature · 1 line
2.31.1
Much better, now we are at a reproducable 10 seconds on my large box. Thanks for all the work on this, now to go and start adding the missing documentation :)
greg k-h
Em Tue, 28 Sep 2021 19:18:31 +0200
Greg Kroah-Hartman <[email protected]> escreveu:
Quoted 84 lines · Mauro Carvalho Chehab
Quoted 83 lines
Em Tue, 28 Sep 2021 13:04:22 +0200
Greg Kroah-Hartman <[email protected]> escreveu:Quoted 15 lines · Mauro Carvalho Chehab
Quoted 14 lines
Hi Greg,
As promised on
https://lore.kernel.org/lkml/[email protected]/T/#uI'm adding progress info when get_abi.pl is checking for undefined ABI symbols on patches 1 and 2.
That will help not only to identify what is causing delays on the script, but also to notify the user that processing it could take some time on some systems.
If you run it on your big server with:
Quoted 8 lines
Quoted 5 lines
scripts/get_abi.plundefined 2>logsThe "logs" file will contain timestamps relative to the time the script started to do the regex matches for sysfs files. It should be printing one line every time the progress completes 1% or one second after the last progress output.
Adding more debugging and tweaking the script a bit to show the file it is about to check, not the one it finished checking,
Feel free to modify the script and add such debug/tweaks if you find it useful.
Quoted 9 lines
I got the following
debug output that seems to pinpoint the problem file.The sysfs file that is causing problems is:
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/capand here's some debugging output for the regex it needs to search for this:
Quoted 12 lines
/sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:00.2/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:07.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:02/device:7a/physical_node/iommu/ivhd1/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/amd\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/class/iommu/.*/intel\-iommu/cap$)$/ /sys/devices/pci0000:40/0000:40:01.3/0000:4a:00.0/0000:4b:0a.0/0000:50:00.0/iommu/amd-iommu/cap =~ /^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/
Hmm... interesting. Perhaps the problem is on regexes like this:
/^(?^:^/sys/devices/pci.*.*.*.*\:.*.*/0000\:.*.*\:.*.*..*/dma/dma.*chan.*/quickdata/cap$)$/Which actually represents this What:
/sys/devices/pciXXXX:XX/0000:XX:XX.X/dma/dma<n>chan<n>/quickdata/capThe script could have done a better job escaping "." character on it (but that is not too trivial) and grouping altogether ".*" repetitions, although, in this specific case, probably the best regex would be, instead:
/sys/devices/pci[\da-f:\.]+/dma/dma\d+chan\d+/quickdata/capOne possible long-term solution would be to directly use regexes directly on "What" fields inside
Documentation/ABI, but on some parts this would require some changes, like, for instance:/sys/bus/usb/devices/<busnum>-<devnum>:<config num>.<interface num>/<hid-bus>:<vendor-id>:<product-id>.<num>/kone/roccatkone<minor>/weightOk, we could likely use capture groups like:
(?<NAME>pattern)but IMO that would make it a lot harder to be understood by humans.
Quoted 3 lines
And sometimes this thing finishes in 20 seconds, and others, many many minutes. It's not deterministic at all, which is odd. Is the sysfs tree being sorted so that this should always have the same search order?
Quoted 8 lines
Quoted 3 lines
No, because it uses a lot of hashes in order to speed it up. Yet, it shouldn't be hard - nor it would significantly affect the processing time - to make it more deterministic. See the enclosed path.
That patch solved everything.
It now only takes 10 seconds. Every time. Without the patch, it feels hung for some reason.
The explanation is simple - still weird :-) - basically, when an ABI symbol is found, the regex test loop stops.
Sorting the regexes probably placed the slowest regex to happen *after* the one that matched the ABI symbol.
Quoted 1 line
Care to turn that into a patch that I can take?
Sure. Just sent it.
Quoted 15 lines
Quoted 6 lines
Quoted 3 lines
Anyway, I've applied this series as well, this helps in finding the problems :)
Thanks!
Quoted 8 lines
Quoted 2 lines
Note, I can provide an off-list tarball of
/sys/if that would help in debugging anything on your end.Yeah, that can help. Feel free to send it to me.
Btw, I just got an arm64 server with 128 CPUs for testing. I'm trying to allocate also a big x86 server here, but I'm not sure if it is AMD or Intel.
Quoted 5 lines
This is on perl 5.34 here.
thanks,
greg k-h
Thanks,
Mauro