Re: armv7-on-aarch64 stuck at urdlck: I got a replication of the "ampere2" bulk build hangup problem on a Windows DevKit 2023

From: Mark Millard <marklmi_at_yahoo.com>
Date: Tue, 16 Jul 2024 18:37:34 UTC
On Jul 16, 2024, at 10:42, Mark Millard <marklmi@yahoo.com> wrote:

> No longer is the problem only observed on ampere2! But this was with
> a non-debug, personally built kernel that has some of my now patches.
> I'll see if I can replicate the issue with an official pkgbase debug
> kernel.

It replicated with the official pkgbase debug kernel. The
kernel did not report anything.

The following commits in main and happen between the last working
ampere2 armv7 builds and the first failing ampere2 builds and
look be the only likely contributors from that range as far as
I could tell:

Tue, 27 Feb 2024
. . .
• git: 1df8700aa6cf - main - PP mutexes: unlock: Reset inherited prio regardless of privileges Olivier Certner 
• git: 9ac3ac9ece62 - main - PP mutexes: lock: Check if priority is too high against base one Olivier Certner 
• git: 39e4665c9694 - main - PP mutexes: lock: Reduce 'umtx_lock' holding before taking the user lock Olivier Certner

These changes are not in 14.0-RELEASE but are in 14.1-STABLE and 14.1-RELEASE.
So I expect that when any ampere*'s progress to 14.1-RELEASE the armv7
problems would start for them.

These changes are not in 13.3-RELEASE but are in 13.3-STABLE. So I expect that
when any ampere*'s progress to 13.4-RELEASE the problems would start for them.


With the prior packages already built in a prior poudriere-devel
run it turns out that just:

# poudriere bulk -j main-armv7-poud -i graphics/graphviz

replicates the problem:

. . .
[00:00:45] Installing graphics/graphviz | graphviz-9.0.0_4
[aarch64PBase] Installing graphviz-9.0.0_4...
[aarch64PBase] `-- Installing cairo-1.17.4_2,3...
[aarch64PBase] |   `-- Installing fontconfig-2.15.0_2,1...
[aarch64PBase] |   | `-- Installing expat-2.6.2...
[aarch64PBase] |   | `-- Extracting expat-2.6.2: 100%
[aarch64PBase] |   | `-- Installing freetype2-2.13.2...
[aarch64PBase] |   |   `-- Installing brotli-1.1.0,1...
[aarch64PBase] |   |   `-- Extracting brotli-1.1.0,1: 100%
[aarch64PBase] |   |   `-- Installing png-1.6.43...
[aarch64PBase] |   |   `-- Extracting png-1.6.43: 100%
[aarch64PBase] |   | `-- Extracting freetype2-2.13.2: 100%
[aarch64PBase] |   `-- Extracting fontconfig-2.15.0_2,1: 100%
[aarch64PBase] |   `-- Installing glib-2.80.4,2...
[aarch64PBase] |   | `-- Installing libffi-3.4.6...
[aarch64PBase] |   | `-- Extracting libffi-3.4.6: 100%
[aarch64PBase] |   | `-- Installing libiconv-1.17_1...
[aarch64PBase] |   | `-- Extracting libiconv-1.17_1: 100%
[aarch64PBase] |   | `-- Installing pcre2-10.43...
[aarch64PBase] |   | `-- Extracting pcre2-10.43: 100%
[aarch64PBase] |   | `-- Installing py311-packaging-24.1...
[aarch64PBase] |   |   `-- Installing python311-3.11.9_1...
[aarch64PBase] |   |   | `-- Installing mpdecimal-4.0.0...
[aarch64PBase] |   |   | `-- Extracting mpdecimal-4.0.0: 100%
[aarch64PBase] |   |   | `-- Installing readline-8.2.10...
[aarch64PBase] |   |   | `-- Extracting readline-8.2.10: 100%
[aarch64PBase] |   |   `-- Extracting python311-3.11.9_1: 100%
[aarch64PBase] |   | `-- Extracting py311-packaging-24.1: 100%
[aarch64PBase] |   `-- Extracting glib-2.80.4,2: 100%
[aarch64PBase] |   `-- Installing libglvnd-1.7.0...
[aarch64PBase] |   `-- Extracting libglvnd-1.7.0: 100%
[aarch64PBase] |   `-- Installing pixman-0.42.2...
[aarch64PBase] |   `-- Extracting pixman-0.42.2: 100%
[aarch64PBase] `-- Extracting cairo-1.17.4_2,3: 100%
[aarch64PBase] `-- Installing harfbuzz-9.0.0...
[aarch64PBase] |   `-- Installing graphite2-1.3.14...
[aarch64PBase] |   `-- Extracting graphite2-1.3.14: 100%
[aarch64PBase] `-- Extracting harfbuzz-9.0.0: 100%
[aarch64PBase] `-- Installing jpeg-turbo-3.0.3...
[aarch64PBase] `-- Extracting jpeg-turbo-3.0.3: 100%
[aarch64PBase] `-- Installing libgd-2.3.3_13,1...
[aarch64PBase] |   `-- Installing tiff-4.6.0...
[aarch64PBase] |   | `-- Installing jbigkit-2.1_3...
[aarch64PBase] |   | `-- Extracting jbigkit-2.1_3: 100%
[aarch64PBase] |   | `-- Installing lerc-4.0.0...
[aarch64PBase] |   | `-- Extracting lerc-4.0.0: 100%
[aarch64PBase] |   | `-- Installing libdeflate-1.20...
[aarch64PBase] |   | `-- Extracting libdeflate-1.20: 100%
[aarch64PBase] |   | `-- Installing zstd-1.5.6...
[aarch64PBase] |   |   `-- Installing liblz4-1.9.4_1,1...
[aarch64PBase] |   |   `-- Extracting liblz4-1.9.4_1,1: 100%
[aarch64PBase] |   | `-- Extracting zstd-1.5.6: 100%
[aarch64PBase] |   `-- Extracting tiff-4.6.0: 100%
[aarch64PBase] |   `-- Installing webp-1.4.0_1...
[aarch64PBase] |   | `-- Installing giflib-5.2.2...
[aarch64PBase] |   | `-- Extracting giflib-5.2.2: 100%
[aarch64PBase] |   `-- Extracting webp-1.4.0_1: 100%
[aarch64PBase] `-- Extracting libgd-2.3.3_13,1: 100%
[aarch64PBase] `-- Installing libltdl-2.4.7...
[aarch64PBase] `-- Extracting libltdl-2.4.7: 100%
[aarch64PBase] `-- Installing pango-1.52.2_1...
[aarch64PBase] |   `-- Installing fribidi-1.0.15...
[aarch64PBase] |   `-- Extracting fribidi-1.0.15: 100%
[aarch64PBase] |   `-- Installing libXft-2.3.8...
[aarch64PBase] |   `-- Extracting libXft-2.3.8: 100%
[aarch64PBase] |   `-- Installing libthai-0.1.29_1...
[aarch64PBase] |   | `-- Installing libdatrie-0.2.13_2...
[aarch64PBase] |   | `-- Extracting libdatrie-0.2.13_2: 100%
[aarch64PBase] |   `-- Extracting libthai-0.1.29_1: 100%
[aarch64PBase] `-- Extracting pango-1.52.2_1: 100%
[aarch64PBase] Extracting graphviz-9.0.0_4: 100%

And here it is hung with /usr/local/bin/dot -c in urdlck :

  0  1483  4502 7  68  0 15760  4872 wait     I+    0    0:03.92 | |   `-- /usr/local/libexec/poudriere/sh -e -o pipefail /usr/local/share/poudriere/bulk.sh -j main-armv7-poud -i graphics/graphviz
  0  1894  1483 5  68  0 15760  4712 nanslp   S     0    0:02.07 | |     |-- sh: poudriere[main-armv7-poud-default]: html_json_main (sh)
  0 25321  1483 6  68  0  6664  3868 wait     I+J   0    0:00.11 | |     `-- /usr/bin/make -C /usr/ports/graphics/graphviz install-package
  0 25322 25321 5  68  0 11140  8860 wait     I+J   0    0:00.00 | |       `-- /usr/local/sbin/pkg-static add /packages/All/graphviz-9.0.0_4.pkg
  0 25323 25322 5  20  0 63824 45144 select   S+J   0    0:02.85 | |         `-- /usr/local/sbin/pkg-static add /packages/All/graphviz-9.0.0_4.pkg
  0 26900 25323 3  68  0 26292 23804 urdlck   I+J   0    0:00.02 | |           `-- /usr/local/bin/dot -c


> FYI for the replication that I got:
> 
> /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
> runs:
> /usr/local/bin/dot -c
> 
> each such /usr/local/bin/dot is stuck at MWCHAN urdlck .
> 
> # poudriere status -b
> [main-armv7-poud-default] [2024-07-16_04h27m31s] [parallel_build] Queued: 449 Built: 433 Failed: 0   Skipped: 0   Ignored: 0   Fetched: 0   Tobuild: 16   Time: 04:44:38
> ID  TOTAL                            ORIGIN   PKGNAME                             PHASE PHASE    TMPFS    CPU% MEM%
> [01] 00:59:45 graphics/rubygem-ruby-graphviz | rubygem-ruby-graphviz-1.2.5   run-depends 00:59:30 1.59 GiB   0% 0.2%
> [02] 00:49:59           graphics/p5-GraphViz | p5-GraphViz-2.25            build-depends 00:49:53 1.45 GiB   0% 0.2%
> [03] 00:59:45        graphics/py-pydot@py311 | py311-pydot-2.0.0             run-depends 00:59:34 1.47 GiB   0% 0.2%
> [04] 00:59:45   graphics/py-pygraphviz@py311 | py311-pygraphviz-1.6          lib-depends 00:59:33 1.47 GiB   0% 0.2%
> [05] 00:58:57     graphics/py-graphviz@py311 | py311-graphviz-0.10.1         run-depends 00:58:49 1.47 GiB   0% 0.2%
> [06] 00:59:20                     audio/ganv | ganv-1.8.2_1                  lib-depends 00:59:10 1.53 GiB   0% 0.2%
> [07] 00:59:45                    devel/libr3 | libr3-1.0.0_2                 lib-depends 00:59:19 1.54 GiB   0% 0.3%
> [08] 00:59:45                     net/netmap | netmap-0.1.3_2                run-depends 00:59:22 1.46 GiB   0% 0.3%
> 
> I had started the bulk build via the list:
> 
> # more ~/origins/ampere2-failures-armv7.txt
> audio/ganv
> devel/doxygen
> devel/libr3
> graphics/p5-GraphViz
> graphics/p5-GraphViz2
> graphics/oyranos
> graphics/pear-Image_GraphViz@php81
> graphics/py-graphviz@py311
> graphics/py-pydot@py311
> graphics/py-pygraphviz@py311
> graphics/rubygem-ruby-graphviz
> math/ggobi
> net-mgmt/librenms
> net/netmap
> print/dot2tex@py311
> 
> # poudriere bulk -j main-armv7-poud `cat ~/origins/ampere2-failures-armv7.txt`
> . . .
> [00:00:12] Building 449 packages using up to 8 builders
> . . .
> [03:44:55] [01] [00:18:54] Finished   graphics/graphviz | graphviz-9.0.0_4: Success
> [03:44:56] [01] [00:00:00] Building   graphics/rubygem-ruby-graphviz | rubygem-ruby-graphviz-1.2.5
> [03:44:56] [03] [00:00:00] Building   graphics/py-pydot@py311 | py311-pydot-2.0.0
> [03:44:56] [04] [00:00:00] Building   graphics/py-pygraphviz@py311 | py311-pygraphviz-1.6
> [03:44:56] [07] [00:00:00] Building   devel/libr3 | libr3-1.0.0_2
> [03:44:56] [08] [00:00:00] Building   net/netmap | netmap-0.1.3_2
> [03:45:21] [06] [00:09:33] Finished   x11-toolkits/gtkmm24 | gtkmm24-2.24.5_4: Success
> [03:45:21] [06] [00:00:00] Building   audio/ganv | ganv-1.8.2_1
> [03:45:44] [05] [00:13:33] Finished   graphics/ImageMagick6@nox11 | ImageMagick6-nox11-6.9.12.77_9,1: Success
> [03:45:44] [05] [00:00:00] Building   graphics/py-graphviz@py311 | py311-graphviz-0.10.1
> [03:54:42] [02] [00:24:53] Finished   print/texlive-base | texlive-base-20240312: Success
> [03:54:42] [02] [00:00:00] Building   graphics/p5-GraphViz | p5-GraphViz-2.25
> 
> In /usr/src/sys/kern/kern_umtx.c there is:
> 
> static int
> do_rw_rdlock(struct thread *td, struct urwlock *rwlock, long fflag,
>    struct _umtx_time *timeout)
> {
> . . .
>                /*
>                 * Contention bit is set, before sleeping, increase
>                 * read waiter count.
>                 */
>                rv = fueword32(&rwlock->rw_blocked_readers,
>                    &blocked_readers);
>                if (rv == 0)
>                        rv = suword32(&rwlock->rw_blocked_readers,
>                            blocked_readers + 1);
>                if (rv == -1) {
>                        umtxq_unbusy_unlocked(&uq->uq_key);
>                        error = EFAULT;
>                        break;
>                }
>                  while (state & wrflags) {
>                        umtxq_lock(&uq->uq_key);
>                        umtxq_insert(uq);
>                        umtxq_unbusy(&uq->uq_key);
>                          error = umtxq_sleep(uq, "urdlck", timeout == NULL ?
>                            NULL : &timo);
>                          umtxq_busy(&uq->uq_key);
>                        umtxq_remove(uq);
>                        umtxq_unlock(&uq->uq_key);
>                        if (error)
>                                break;
>                        rv = fueword32(&rwlock->rw_state, &state);
>                        if (rv == -1) {
>                                error = EFAULT;
>                                break;
>                        }
>                }
> 
> . . .
> 
> 
> 
> For reference:
> 
> # ps -alxdww | less
> UID   PID  PPID C PRI NI   VSZ   RSS MWCHAN   STAT TT         TIME COMMAND
> . . .
>  0 87700  4522 6  20  0 16576  1888 -        T     0      0:00.01 | |   |-- vi /usr/local/share/poudriere/jail.sh
>  0 91496  4522 4  20  0 15760  4684 select   S+    0      0:06.88 | |   `-- /usr/local/libexec/poudriere/sh -e -o pipefail /usr/local/share/poudriere/bulk.sh audio/ganv devel/doxygen devel/libr3 graphics/p5-GraphViz graphics/p5-GraphViz2 graphics/oyranos graphics/pear-Image_GraphViz@php81 graphics/py-graphviz@py311 graphics/py-pydot@py311 graphics/py-pygraphviz@py311 graphics/rubygem-ruby-graphviz math/ggobi net-mgmt/librenms net/netmap print/dot2tex@py311
>  0 37688 91496 0  68  0 15760  4700 wait     I     0      0:00.05 | |     |-- sh: poudriere[main-armv7-poud-default][01]: build_pkg (rubygem-ruby-graphviz-1.2.5) (sh)
>  0 47568 37688 0  68  0  6664  3664 wait     IJ    0      0:00.03 | |     | `-- /usr/bin/make -C /usr/ports/graphics/rubygem-ruby-graphviz run-depends
>  0 47598 47568 6  68  0  5568  2988 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 47743 47598 6  68  0 11188  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 47747 47743 3  20  0 71692 48984 select   SJ    0      0:04.26 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 56383 47747 1  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 37700 91496 6  68  0 15760  4700 wait     I     0      0:00.04 | |     |-- sh: poudriere[main-armv7-poud-default][03]: build_pkg (py311-pydot-2.0.0) (sh)
>  0 45102 37700 2  68  0  6668  3704 wait     IJ    0      0:00.02 | |     | `-- /usr/bin/make -C /usr/ports/graphics/py-pydot FLAVOR=py311 run-depends
>  0 45156 45102 4  68  0  5584  2992 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 45215 45156 4  68  0 11144  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 45218 45215 4  20  0 51420 31512 select   SJ    0      0:02.68 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 52147 45218 2  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 37721 91496 1  68  0 15760  4700 wait     I     0      0:00.04 | |     |-- sh: poudriere[main-armv7-poud-default][04]: build_pkg (py311-pygraphviz-1.6) (sh)
>  0 45937 37721 1  68  0  6684  3744 wait     IJ    0      0:00.03 | |     | `-- /usr/bin/make -C /usr/ports/graphics/py-pygraphviz FLAVOR=py311 lib-depends
>  0 46009 45937 7  68  0  5584  2992 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 46127 46009 7  68  0 11144  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 46129 46127 1  20  0 51384 31548 select   SJ    0      0:02.73 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 53311 46129 4  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 37744 91496 7  45  0 15760  4692 wait     I     0      0:00.04 | |     |-- sh: poudriere[main-armv7-poud-default][07]: build_pkg (libr3-1.0.0_2) (sh)
>  0 55198 37744 0  50  0  6664  3664 wait     IJ    0      0:00.03 | |     | `-- /usr/bin/make -C /usr/ports/devel/libr3 lib-depends
>  0 55229 55198 0  68  0  5588  2988 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 55594 55229 7  68  0 11168  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 55596 55594 2  20  0 69796 50180 select   SJ    0      0:04.53 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 62753 55596 0  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 37763 91496 4  29  0 15760  4696 wait     I     0      0:00.05 | |     |-- sh: poudriere[main-armv7-poud-default][08]: build_pkg (netmap-0.1.3_2) (sh)
>  0 51054 37763 6  36  0  6636  3684 wait     IJ    0      0:00.03 | |     | `-- /usr/bin/make -C /usr/ports/net/netmap run-depends
>  0 51107 51054 3  68  0  5568  2988 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 51576 51107 3  68  0 11168  8860 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 51580 51576 3  20  0 68220 49432 select   SJ    0      0:04.27 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 59063 51580 6  68  0 26292 23808 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 53709 91496 1  68  0 15760  4700 wait     I     0      0:00.04 | |     |-- sh: poudriere[main-armv7-poud-default][06]: build_pkg (ganv-1.8.2_1) (sh)
>  0 63371 53709 6  68  0  6636  3668 wait     IJ    0      0:00.03 | |     | `-- /usr/bin/make -C /usr/ports/audio/ganv lib-depends
>  0 63377 63371 1  68  0  5580  2996 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 63413 63377 4  68  0 11180  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 63414 63413 3  20  0 56212 35980 select   SJ    0      0:02.21 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 65577 63414 6  68  0 26292 23812 urdlck   IJ    0      0:00.01 | |     |         `-- /usr/local/bin/dot -c
>  0 63365 91496 3  68  0 15760  4696 wait     I     0      0:00.03 | |     |-- sh: poudriere[main-armv7-poud-default][02]: build_pkg (p5-GraphViz-2.25) (sh)
>  0 63807 63365 7  68  0  6696  3672 wait     IJ    0      0:00.02 | |     | `-- /usr/bin/make -C /usr/ports/graphics/p5-GraphViz build-depends
>  0 63808 63807 2  68  0  5568  2988 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 63833 63808 4  68  0 11188  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 63834 63833 7  20  0 67400 48532 select   SJ    0      0:03.52 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 66041 63834 2  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 69974 91496 1  68  0 15760  4700 wait     I     0      0:00.04 | |     |-- sh: poudriere[main-armv7-poud-default][05]: build_pkg (py311-graphviz-0.10.1) (sh)
>  0 73474 69974 5  68  0  6684  3740 wait     IJ    0      0:00.02 | |     | `-- /usr/bin/make -C /usr/ports/graphics/py-graphviz FLAVOR=py311 run-depends
>  0 73496 73474 6  68  0  5584  2992 wait     IJ    0      0:00.01 | |     |   `-- /bin/sh /usr/ports/Mk/Scripts/do-depends.sh
>  0 73521 73496 7  68  0 11144  8864 wait     IJ    0      0:00.00 | |     |     `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 73522 73521 0  20  0 52432 32664 select   SJ    0      0:02.70 | |     |       `-- /usr/local/sbin/pkg-static add -A /packages/All/graphviz-9.0.0_4.pkg
>  0 76540 73522 3  68  0 26292 23812 urdlck   IJ    0      0:00.02 | |     |         `-- /usr/local/bin/dot -c
>  0 91907 91496 5  68  0 15760  4492 nanslp   S     0      1:05.17 | |     |-- sh: poudriere[main-armv7-poud-default]: html_json_main (sh)
>  0 99134 91496 1  40  0 15760  4740 piperd   I     0      0:03.22 | |     `-- sh: poudriere[main-armv7-poud-default]: pkg_cacher_main (sh)
>  0 23


===
Mark Millard
marklmi at yahoo.com