Re: armv7-on-aarch64 stuck at urdlck: I got a replication of the "ampere2" bulk build hangup problem on a Windows DevKit 2023
- Reply: Konstantin Belousov : "Re: armv7-on-aarch64 stuck at urdlck: I got a replication of the "ampere2" bulk build hangup problem on a Windows DevKit 2023"
- Reply: Mark Millard : "[main has a fix for] Re: armv7-on-aarch64 stuck at urdlck: I got a replication of the "ampere2" bulk build hangup problem on a Windows DevKit 2023"
- In reply to: Mark Millard : "Re: armv7-on-aarch64 stuck at urdlck: I got a replication of the "ampere2" bulk build hangup problem on a Windows DevKit 2023"
- Go to: [ bottom of page ] [ top of archives ] [ this month ]
Date: Sat, 20 Jul 2024 05:38:36 UTC
On Jul 18, 2024, at 01:14, Mark Millard <marklmi@yahoo.com> wrote:
> On Jul 16, 2024, at 23:45, Mark Millard <marklmi@yahoo.com> wrote:
>
>> On Jul 16, 2024, at 18:41, Mark Millard <marklmi@yahoo.com> wrote:
>>
>>> On Jul 16, 2024, at 11:37, Mark Millard <marklmi@yahoo.com> wrote:
>>>
>>>> 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
>>>
>>>
>>> A little bit more context for /usr/local/bin/dot :
>>>
>>> 0x20631520 in _umtx_op () from /lib/libsys.so.7
>>> (gdb) bt
>>> #0 0x20631520 in _umtx_op () at /lib/libsys.so.7
>>> #1 0x2063245c in _umtx_op_err () at /lib/libsys.so.7
>>> #2 0x203a2da8 in ??? () at /lib/libthr.so.3
>>> #3 0x2039bbf4 in ??? () at /lib/libthr.so.3
>>> #4 0x20061788 in ??? () at /libexec/ld-elf.so.1
>>>
>>> And the associated instance of /usr/local/sbin/pkg-static :
>>>
>>> (gdb) bt
>>> #0 _poll () at _poll.S:4
>>> #1 0x007669e0 in __thr_poll (fds=0xd1, nfds=1, timeout=1000) at /home/pkgbuild/worktrees/main/lib/libthr/thread/thr_syscalls.c:320
>>> #2 0x003602e8 in pkg_script_run_child (pid=64019, pstat=pstat@entry=0xffffc49c, inputfd=9, script_name=0x5d5c9 "POST-INSTALL") at scripts.c:303
>>> #3 0x0035fc34 in pkg_script_run (pkg=0x20972e00, type=<optimized out>, upgrade=<optimized out>) at scripts.c:227
>>> #4 0x00371250 in pkg_add_common (db=<optimized out>, path=<optimized out>, path@entry=0xffffda7f "/packages/All/graphviz-9.0.0_4.pkg", flags=<optimized out>, reloc=<optimized out>, remote=0x0, local=0x0, t=0x0) at pkg_add.c:1386
>>> #5 0x003707e4 in pkg_add (db=0x4, path=0x1 <error: Cannot access memory at address 0x1>, path@entry=0xffffda7f "/packages/All/graphviz-9.0.0_4.pkg", flags=1000, location=0x766990 <__thr_poll> "\360H-\351\020\260\215\342") at pkg_add.c:1460
>>> #6 0x00194544 in exec_add (argc=<optimized out>, argv=<optimized out>) at add.c:178
>>> #7 0x0019f840 in main (argc=2, argv=0xffffd87c) at main.c:872
>>>
>>>
>>
>> Continued experiments point in a different direction
>> via an simpler test of just use of "dot -c":
>>
>> # /usr/local/bin/dot -c
>> Error: /usr/local/lib/graphviz/config6 is zero sized.
>>
>> And after the Error: line dot is hung up like it is
>> when used via pkg-static.
>>
>> It seems that whatever leads to the "Error:" line
>> output and that conidition's handling in dot is the
>> source of the hangup.
>>
>> "dot -c" generates configuration file content for
>> plugins and, appearently, should not gnerate an
>> empty config6 file.
>
>
> Well, I get to:
>
> (gdb) bt
> #0 0x2005acc0 in dlopen () from /libexec/ld-elf.so.1
> #1 0x201b87fc in vm_open (loader_data=<optimized out>, filename=filename@entry=0x20662540 "/usr/local/lib/graphviz/libgvplugin_gd.so.6", advise=<optimized out>, advise@entry=0x0)
> at loaders/dlopen.c:211
> #2 0x201b6f24 in tryall_dlopen (phandle=<optimized out>, phandle@entry=0xffffd978, filename=0x20662540 "/usr/local/lib/graphviz/libgvplugin_gd.so.6", advise=0x0, vtable=0x0) at ltdl.c:444
> #3 0x201b52d0 in try_dlopen (phandle=phandle@entry=0xffffd9b0, filename=<optimized out>, filename@entry=0x20665040 "/usr/local/lib/graphviz/libgvplugin_gd.so.6", ext=0x20662599 ".6", advise=<optimized out>) at ltdl.c:1481
> #4 0x201b4d34 in lt_dlopenadvise (filename=0x20665040 "/usr/local/lib/graphviz/libgvplugin_gd.so.6", advise=0x0) at ltdl.c:1671
> #5 lt_dlopen (filename=0x1 <error: Cannot access memory at address 0x1>) at ltdl.c:1626
> #6 0x200e255c in ?? ()
>
> But the dlopen does not return. One possible point of interest
> is that /usr/local/lib/graphviz/libgvplugin_gd.so.6 leads to
> loading a bunch of libraries, including the first/only load of
> /lib/libc++.so.1 and libcxxrt.so.1 ( via
> /usr/local/lib/libLerc.so.4 ).
Two more basic tests and relted information from
an example failure:
) I replicated the problem on a RPi4B, so before any modern armv8.* .
) I mounted a stable/14 and chrooted to it but based on the main
kernel I've been using. stable/14 did not repeat the problem.
That last likely means that main's kernel is not the problem.
It suggests code specific to main that is not in stable/14 is
at issue.
An example could be libsys and changes made to it during the
interval between the last known working and the first known failure.
A simple program source to reproduce the problem in a main armv7
chroot on a main aarch64 is:
# more dlopen_test.c
// FAILS:
// cc -g -std=c11 -pedantic -Wall -pthread dlopen_test.c ; ./a.out
// Works:
// cc -g -std=c11 -pedantic -Wall dlopen_test.c ; ./a.out
#include <dlfcn.h>
int main(void)
{
// ANY OF THE FOLLOWING FAIL with -pthread specified:
// dlopen("/usr/local/lib/graphviz/libgvplugin_gd.so.6.0.0",RTLD_LAZY);
// dlopen("/usr/local/lib/libpangocairo-1.0.so.0",RTLD_LAZY);
dlopen("/usr/local/lib/libcairo.so.2",RTLD_LAZY);
}
so -pthread seems essential.
# truss -fae ./a.out
13114: mmap(0x0,135168,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 537444352 (0x2008c000)
13114: mprotect(0x2007a000,4096,PROT_READ) = 0 (0x0)
. . .
open("/lib/libthr.so.3",O_RDONLY|O_CLOEXEC|O_VERIFY,04002220025) = 3 (0x3)
13114: fstat(3,{ mode=-r--r--r-- ,inode=91507361,size=122044,blksize=32768 }) = 0 (0x0)
13114: mmap(0x0,4096,PROT_READ,MAP_PRIVATE|MAP_PREFAULT_READ,3,0x0) = 537153536 (0x20045000)
13114: mmap(0x0,356352,PROT_NONE,MAP_GUARD,-1,0x0) = 537829376 (0x200ea000)
13114: mmap(0x200ea000,32768,PROT_READ,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE|MAP_PREFAULT_READ,3,0x0) = 537829376 (0x200ea000)
13114: mmap(0x20101000,90112,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE|MAP_PREFAULT_READ,3,0x7000) = 537923584 (0x20101000)
13114: mmap(0x20126000,8192,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_PREFAULT_READ,3,0x1c000) = 538075136 (0x20126000)
13114: mmap(0x20137000,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_PREFAULT_READ,3,0x1d000) = 538144768 (0x20137000)
13114: mmap(0x20138000,36864,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_ANON,-1,0x0) = 538148864 (0x20138000)
13114: munmap(0x20045000,4096) = 0 (0x0)
13114: close(3) = 0 (0x0)
. . .
13114: mprotect(0x20ff0000,4096,PROT_READ) = 0 (0x0)
13114: mprotect(0x21025000,4096,PROT_READ) = 0 (0x0)
13114: mprotect(0x210a4000,4096,PROT_READ) = 0 (0x0)
13114: mprotect(0x210fc000,4096,PROT_READ) = 0 (0x0)
load: 0.53 cmd: a.out 13114 [urdlck] 38.23r 0.00u 0.00s 0% 10132k
#0 0xffff0000004be9b8 at mi_switch+0x184
#1 0xffff000000513880 at sleepq_switch+0xf0
#2 0xffff000000513ca8 at sleepq_catch_signals+0x2bc
#3 0xffff0000005139bc at sleepq_wait_sig+0xc
#4 0xffff0000004bdd54 at _sleep+0x278
#5 0xffff0000004d3088 at umtxq_sleep+0x2b0
#6 0xffff0000004daadc at do_rw_rdlock+0x36c
#7 0xffff0000004d4ed8 at freebsd32__umtx_op+0x5c
#8 0xffff00000086cee4 at do_el0_sync+0x5dc
#9 0xffff00000084493c at handle_el0_sync+0x4c
^C13114: _umtx_op(0x20137c40,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) ERR#4 'Interrupted system call'
13114: SIGNAL 2 (SIGINT) code=SI_KERNEL
13114: process killed, signal = 2
Note 0x20137c40 is associated with open("/lib/libthr.so.3", . . .)
activity:
13114: mmap(0x20137000,4096,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_PREFAULT_READ,3,0x1d000) = 538144768 (0x20137000)
also, in gdb:
0x201375c0 - 0x2014092c is .bss in /lib/libthr.so.3
(gdb) bt
#0 0x201aeec0 in __pthread_map_stacks_exec () from /lib/libc.so.7
#1 0x2005d1e4 in ?? () from /libexec/ld-elf.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) disass
Dump of assembler code for function __pthread_map_stacks_exec:
=> 0x201aeec0 <+0>: ldr r0, [pc, #8] @ 0x201aeed0 <__pthread_map_stacks_exec+16>
0x201aeec4 <+4>: add r0, pc, r0
0x201aeec8 <+8>: ldr r0, [r0, #156] @ 0x9c
0x201aeecc <+12>: bx r0
0x201aeed0 <+16>: andseq r6, r7, r4, lsr #12
End of assembler dump.
FYI:
(gdb) run
Starting program: /root/a.out
Catchpoint 1
Inferior loaded /lib/libgcc_s.so.1
/lib/libthr.so.3
/lib/libc.so.7
/lib/libsys.so.7
0x20058998 in r_debug_state () from /libexec/ld-elf.so.1
(gdb) bt
#0 0x20058998 in r_debug_state () from /libexec/ld-elf.so.1
#1 0x2005cca4 in ?? () from /libexec/ld-elf.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) c
Continuing.
Catchpoint 1
Inferior loaded /usr/local/lib/libcairo.so.2
/usr/local/lib/libpixman-1.so.0
/usr/local/lib/libfontconfig.so.1
/usr/local/lib/libfreetype.so.6
/usr/local/lib/libEGL.so.1
/usr/lib/libdl.so.1
/usr/local/lib/libpng16.so.16
/usr/local/lib/libxcb-shm.so.0
/usr/local/lib/libxcb.so.1
/usr/local/lib/libxcb-render.so.0
/usr/local/lib/libXrender.so.1
/usr/local/lib/libX11.so.6
/usr/local/lib/libXext.so.6
/lib/libz.so.6
/usr/local/lib/libGL.so.1
/lib/libm.so.5
/usr/local/lib/libexpat.so.1
/usr/lib/libbz2.so.4
/usr/local/lib/libbrotlidec.so.1
/usr/local/lib/libGLdispatch.so.0
/usr/local/lib/libXau.so.6
/usr/local/lib/libXdmcp.so.6
/usr/local/lib/libGLX.so.0
/usr/local/lib/libbrotlicommon.so.1
0x20058998 in r_debug_state () from /libexec/ld-elf.so.1
(gdb) bt
#0 0x20058998 in r_debug_state () from /libexec/ld-elf.so.1
#1 0x2005d184 in ?? () from /libexec/ld-elf.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) s
Single stepping until exit from function r_debug_state,
which has no line number information.
0x201aeec0 in __pthread_map_stacks_exec () from /lib/libc.so.7
(gdb) bt
#0 0x201aeec0 in __pthread_map_stacks_exec () from /lib/libc.so.7
#1 0x2005d1e4 in ?? () from /libexec/ld-elf.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) disass
Dump of assembler code for function __pthread_map_stacks_exec:
=> 0x201aeec0 <+0>: ldr r0, [pc, #8] @ 0x201aeed0 <__pthread_map_stacks_exec+16>
0x201aeec4 <+4>: add r0, pc, r0
0x201aeec8 <+8>: ldr r0, [r0, #156] @ 0x9c
0x201aeecc <+12>: bx r0
0x201aeed0 <+16>: andseq r6, r7, r4, lsr #12
End of assembler dump.
(gdb) si
0x201aeec4 in __pthread_map_stacks_exec () from /lib/libc.so.7
(gdb) si
0x201aeec8 in __pthread_map_stacks_exec () from /lib/libc.so.7
(gdb) si
0x201aeecc in __pthread_map_stacks_exec () from /lib/libc.so.7
(gdb) si
0x20112d98 in ?? () from /lib/libthr.so.3
(gdb) bt
#0 0x20112d98 in ?? () from /lib/libthr.so.3
#1 0x20059e4c in ?? () from /libexec/ld-elf.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
===
Mark Millard
marklmi at yahoo.com