Re: FYI: Over 2 hours spent (so far) in /usr/local/share/poudriere/processonelog.sh executing bzgrep commands for www/chromium failure

On 2021-Aug-6, at 17:39, Mark Millard via freebsd-toolchain <freebsd-toolchain at freebsd.org> wrote:

> On 2021-Aug-6, at 14:24, linimon@portsmon.org linimon@portsmon.org <linimon at portsmon.org> wrote:
>> 
>>> On 08/04/2021 4:43 PM Mark Millard via freebsd-toolchain <freebsd-toolchain at freebsd.org> wrote:
>>> it has spent over 2 hours (so far) doing:
>>> 
>>> /usr/local/share/poudriere/processonelog.sh activity ( /usr/bin/bzgrep 's ) of/for:
>> 
>> fwiw processonelog.sh is not part of the toolchain per se.  It is a script that is part
>> of poudriere.
> 
> poudriere clearly is not part of the buildworld buildkernel
> support.
> 
> Since poudriere is used as infrastructure for building
> ports into packages, including use on one or more
> aarch64 systems for such, I took a guess that toolchain
> was more appropriate than ports for what list to use.
> Sorry if I guessed wrong.
> 
>> I have maintained it in various incarnations over the years.
> 
>> One of the things that I have tried to do is minimize the time the script takes in a run
>> over the errorlogs for an entire build.  These generally complete in around a minute or so.
> 
> Until attempting www/chromium builds, I'd never noticed
> the time frame but in this case I was monitoring with top,
> as well as waiting for pouriere's next output after it
> reported having saved the wrkdir.
> 
> In the end it was about 2 hr 50 min. Part of this is
> likely just the size of a log file from a www/chromium
> build attempt that gets near the end.
> 
> The actual log file is not compressed and can be looked at
> with just less or more or the like. Such is how I normally
> take a preliminary look at build failures.
> 
>> You will need to figure out how big your logfile is, and compare it to the size of a
>> successful logfile, to figure out what is going on.
>> 
> 
> Unfortunately the system involved is down/not-accessible
> for about a day or two. So I'll not be able to check
> details for a while.
> 
> The www/chromium build is huge and my original report
> lists the size of the log file in the "ls -LTld" output:
> 153683812 . So, between 146 MiByte and 147 MiByte.
> 
> A successful build's log file would be larger. The build
> only made it into the 94% range for what ninja reports
> about steps executed. (Unfortunately, rebuilds use
> different alternative orderings that satisfy the partial
> ordering criteria. So build to build varies. I've also
> seen 77% for the same failure on the same file.)
> 
> For reference: the (root) file system is on an Optane
> 480 GiByte in the PCIe 3 slot and is a ZFS file system.
> The system has 64 GiByte of RAM. The swap partitioning
> is on the same media.
> 
> For reference:
> Using USE_TMPFS="yes" lead to the tmpfs for the wrkdir
> involved being over 99000 MiByte (so somewhat under
> 100 GiByte). The system configuration was sufficient to
> not run out of swap/paging space, 64 GiByte of RAM + 120
> GiByte of swap-space. I've since adjusted to just have
> USE_TMPFS="data" now that I know of an example of such a
> huge wrkdir. (lang/rust ends up with a small wrkdir
> peak size, by comparison to www/chromium anyway.)
> 
> 
> Until I again get access to the system, that is about
> all I can report.

Here is a "time -l" for one of the bzgrep's that is involved,
the first:

# time -l bzgrep -qE "(Error: mtree file ./etc/mtree/BSD.local.dist. is missing|error in pkg_delete|filesystem was touched prior to .make install|list of extra files and directories|listof files present before this port was installed|list of filesystem changes from before and after|Error: Files or directories left over|Error: Filesystem touched during build)" /usr/local/poudriere/data/logs/bulk/main-CA72-default/2021-08-03_22h54m48s/logs/chromium-91.0.4472.114.log
      806.63 real       806.63 user         0.19 sys
      2476  maximum resident set size
        20  average shared memory size
         8  average unshared data size
       128  average unshared stack size
       496  page reclaims
         0  page faults
         0  swaps
         0  block input operations
         0  block output operations
     37521  messages sent
      4691  messages received
         0  signals received
      7138  voluntary context switches
      8536  involuntary context switches

Using grep directly is not much different
for the times:

# time -l grep -qE "(Error: mtree file ./etc/mtree/BSD.local.dist. is missing|error in pkg_delete|filesystem was touched prior to .make install|list of extra files and directories|list of files present before this port was installed|list of filesystem changes from before and after|Error: Files or directories left over|Error: Filesystem touched during build)" /usr/local/poudriere/data/logs/bulk/main-CA72-default/2021-08-03_22h54m48s/logs/chromium-91.0.4472.114.log
      804.02 real       803.86 user         0.18 sys
      2476  maximum resident set size
        19  average shared memory size
         7  average unshared data size
       127  average unshared stack size
       158  page reclaims
         0  page faults
         0  swaps
       579  block input operations
         0  block output operations
         0  messages sent
         0  messages received
         0  signals received
      2432  voluntary context switches
      9089  involuntary context switches


===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)