0s autopkgtest [20:34:20]: starting date and time: 2025-05-04 20:34:20+0000 0s autopkgtest [20:34:20]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [20:34:20]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.lcp5or3t/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,localhost,localdomain,internal,login.ubuntu.com,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:sqlite3 --apt-upgrade asterisk --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=sqlite3/3.46.1-4 -- lxd -r lxd-armhf-10.145.243.254 lxd-armhf-10.145.243.254:autopkgtest/ubuntu/questing/armhf 21s autopkgtest [20:34:41]: testbed dpkg architecture: armhf 23s autopkgtest [20:34:43]: testbed apt version: 3.0.0 27s autopkgtest [20:34:47]: @@@@@@@@@@@@@@@@@@@@ test bed setup 29s autopkgtest [20:34:49]: testbed release detected to be: None 37s autopkgtest [20:34:57]: updating testbed package index (apt update) 39s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 39s Get:2 http://ftpmaster.internal/ubuntu questing InRelease [110 kB] 39s Get:3 http://ftpmaster.internal/ubuntu questing-updates InRelease [110 kB] 39s Get:4 http://ftpmaster.internal/ubuntu questing-security InRelease [110 kB] 39s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [1095 kB] 40s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [33.9 kB] 40s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [111 kB] 40s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main armhf Packages [132 kB] 40s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe armhf Packages [1019 kB] 40s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse armhf Packages [28.4 kB] 40s Get:11 http://ftpmaster.internal/ubuntu questing/main Sources [1395 kB] 40s Get:12 http://ftpmaster.internal/ubuntu questing/universe Sources [21.3 MB] 40s Get:13 http://ftpmaster.internal/ubuntu questing/multiverse Sources [306 kB] 40s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf Packages [1358 kB] 40s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf Packages [15.3 MB] 41s Get:16 http://ftpmaster.internal/ubuntu questing/multiverse armhf Packages [180 kB] 44s Fetched 42.7 MB in 5s (7952 kB/s) 46s Reading package lists... 51s autopkgtest [20:35:11]: upgrading testbed (apt dist-upgrade and autopurge) 53s Reading package lists... 54s Building dependency tree... 54s Reading state information... 55s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 55s Starting 2 pkgProblemResolver with broken count: 0 55s Done 57s Entering ResolveByKeep 57s 58s Calculating upgrade... 59s The following packages will be upgraded: 59s base-files base-passwd cloud-init cloud-init-base debianutils 59s distro-info-data dpkg dpkg-dev ed ethtool fwupd htop iso-codes libbpf1 59s libdpkg-perl libevdev2 libftdi1-2 libfwupd3 libjcat1 libmbim-glib4 59s libmbim-proxy libmm-glib0 libnftnl11 libnghttp2-14 libnpth0t64 libnvme1t64 59s libqmi-glib5 libqmi-proxy libsensors-config libsensors5 libsepol2 59s libsqlite3-0 libunistring5 liburcu8t64 libusb-1.0-0 man-db motd-news-config 59s nano patch publicsuffix python3-lazr.restfulclient python3-more-itertools 59s python3-s3transfer sos ubuntu-pro-client ubuntu-pro-client-l10n usb.ids 59s usbutils 59s 48 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 59s Need to get 15.6 MB of archives. 59s After this operation, 1221 kB disk space will be freed. 59s Get:1 http://ftpmaster.internal/ubuntu questing/main armhf motd-news-config all 13.7ubuntu1 [5260 B] 59s Get:2 http://ftpmaster.internal/ubuntu questing/main armhf base-files armhf 13.7ubuntu1 [75.4 kB] 59s Get:3 http://ftpmaster.internal/ubuntu questing/main armhf debianutils armhf 5.22 [92.2 kB] 59s Get:4 http://ftpmaster.internal/ubuntu questing/main armhf dpkg armhf 1.22.18ubuntu3 [1254 kB] 59s Get:5 http://ftpmaster.internal/ubuntu questing/main armhf base-passwd armhf 3.6.7 [53.9 kB] 59s Get:6 http://ftpmaster.internal/ubuntu questing/main armhf libsepol2 armhf 3.8.1-1 [282 kB] 59s Get:7 http://ftpmaster.internal/ubuntu questing/main armhf libnpth0t64 armhf 1.8-3 [7716 B] 60s Get:8 http://ftpmaster.internal/ubuntu questing/main armhf distro-info-data all 0.64 [6664 B] 60s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf iso-codes all 4.18.0-1 [3703 kB] 60s Get:10 http://ftpmaster.internal/ubuntu questing/main armhf libbpf1 armhf 1:1.5.0-3 [158 kB] 60s Get:11 http://ftpmaster.internal/ubuntu questing-proposed/main armhf libsqlite3-0 armhf 3.46.1-4 [602 kB] 60s Get:12 http://ftpmaster.internal/ubuntu questing/main armhf libunistring5 armhf 1.3-2 [583 kB] 60s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client-l10n armhf 35.1ubuntu0 [19.7 kB] 60s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client armhf 35.1ubuntu0 [258 kB] 60s Get:15 http://ftpmaster.internal/ubuntu questing/main armhf ed armhf 1.21.1-1 [53.0 kB] 60s Get:16 http://ftpmaster.internal/ubuntu questing/main armhf ethtool armhf 1:6.14-2 [230 kB] 60s Get:17 http://ftpmaster.internal/ubuntu questing/main armhf libevdev2 armhf 1.13.4+dfsg-1 [29.8 kB] 60s Get:18 http://ftpmaster.internal/ubuntu questing/main armhf libnftnl11 armhf 1.2.9-1 [53.3 kB] 60s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf libnghttp2-14 armhf 1.64.0-1.1 [68.5 kB] 60s Get:20 http://ftpmaster.internal/ubuntu questing/main armhf libsensors-config all 1:3.6.2-2 [6756 B] 60s Get:21 http://ftpmaster.internal/ubuntu questing/main armhf libsensors5 armhf 1:3.6.2-2 [26.8 kB] 60s Get:22 http://ftpmaster.internal/ubuntu questing/main armhf liburcu8t64 armhf 0.15.2-2 [57.3 kB] 60s Get:23 http://ftpmaster.internal/ubuntu questing/main armhf libusb-1.0-0 armhf 2:1.0.28-1 [50.0 kB] 60s Get:24 http://ftpmaster.internal/ubuntu questing/main armhf man-db armhf 2.13.1-1 [1341 kB] 60s Get:25 http://ftpmaster.internal/ubuntu questing/main armhf nano armhf 8.4-1 [278 kB] 60s Get:26 http://ftpmaster.internal/ubuntu questing/main armhf publicsuffix all 20250328.1952-0.1 [135 kB] 60s Get:27 http://ftpmaster.internal/ubuntu questing/main armhf usb.ids all 2025.04.01-1 [223 kB] 60s Get:28 http://ftpmaster.internal/ubuntu questing/main armhf usbutils armhf 1:018-2 [77.4 kB] 60s Get:29 http://ftpmaster.internal/ubuntu questing/main armhf cloud-init-base all 25.2~1g7a0265d3-0ubuntu1 [619 kB] 60s Get:30 http://ftpmaster.internal/ubuntu questing/main armhf dpkg-dev all 1.22.18ubuntu3 [1089 kB] 60s Get:31 http://ftpmaster.internal/ubuntu questing/main armhf libdpkg-perl all 1.22.18ubuntu3 [281 kB] 60s Get:32 http://ftpmaster.internal/ubuntu questing/main armhf patch armhf 2.8-1 [94.1 kB] 60s Get:33 http://ftpmaster.internal/ubuntu questing/main armhf libjcat1 armhf 0.2.3-1 [30.9 kB] 60s Get:34 http://ftpmaster.internal/ubuntu questing/main armhf fwupd armhf 2.0.8-3 [1414 kB] 60s Get:35 http://ftpmaster.internal/ubuntu questing/main armhf libfwupd3 armhf 2.0.8-3 [126 kB] 60s Get:36 http://ftpmaster.internal/ubuntu questing/main armhf libmbim-proxy armhf 1.32.0-1 [5888 B] 60s Get:37 http://ftpmaster.internal/ubuntu questing/main armhf libmbim-glib4 armhf 1.32.0-1 [218 kB] 60s Get:38 http://ftpmaster.internal/ubuntu questing/main armhf libmm-glib0 armhf 1.24.0-1 [223 kB] 60s Get:39 http://ftpmaster.internal/ubuntu questing/main armhf libqmi-proxy armhf 1.36.0-1 [5882 B] 60s Get:40 http://ftpmaster.internal/ubuntu questing/main armhf libqmi-glib5 armhf 1.36.0-1 [936 kB] 60s Get:41 http://ftpmaster.internal/ubuntu questing/main armhf htop armhf 3.4.1-4 [147 kB] 60s Get:42 http://ftpmaster.internal/ubuntu questing/main armhf libftdi1-2 armhf 1.5-10 [27.8 kB] 60s Get:43 http://ftpmaster.internal/ubuntu questing/main armhf libnvme1t64 armhf 1.13-2 [74.3 kB] 60s Get:44 http://ftpmaster.internal/ubuntu questing/main armhf python3-lazr.restfulclient all 0.14.6-3 [51.0 kB] 60s Get:45 http://ftpmaster.internal/ubuntu questing/main armhf python3-more-itertools all 10.7.0-1 [59.6 kB] 60s Get:46 http://ftpmaster.internal/ubuntu questing/main armhf python3-s3transfer all 0.11.4-1 [55.8 kB] 60s Get:47 http://ftpmaster.internal/ubuntu questing/main armhf sos all 4.9.1-1 [367 kB] 60s Get:48 http://ftpmaster.internal/ubuntu questing/main armhf cloud-init all 25.2~1g7a0265d3-0ubuntu1 [2106 B] 61s Preconfiguring packages ... 61s Fetched 15.6 MB in 1s (12.8 MB/s) 61s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 61s Preparing to unpack .../motd-news-config_13.7ubuntu1_all.deb ... 61s Unpacking motd-news-config (13.7ubuntu1) over (13.6ubuntu2) ... 61s Preparing to unpack .../base-files_13.7ubuntu1_armhf.deb ... 61s Unpacking base-files (13.7ubuntu1) over (13.6ubuntu2) ... 61s Setting up base-files (13.7ubuntu1) ... 61s Installing new version of config file /etc/issue ... 61s Installing new version of config file /etc/issue.net ... 61s Installing new version of config file /etc/lsb-release ... 62s motd-news.service is a disabled or a static unit not running, not starting it. 62s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 62s Preparing to unpack .../debianutils_5.22_armhf.deb ... 62s Unpacking debianutils (5.22) over (5.21) ... 62s Setting up debianutils (5.22) ... 62s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 62s Preparing to unpack .../dpkg_1.22.18ubuntu3_armhf.deb ... 62s Unpacking dpkg (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 63s Setting up dpkg (1.22.18ubuntu3) ... 63s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 63s Preparing to unpack .../base-passwd_3.6.7_armhf.deb ... 63s Unpacking base-passwd (3.6.7) over (3.6.6) ... 63s Setting up base-passwd (3.6.7) ... 63s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 63s Preparing to unpack .../libsepol2_3.8.1-1_armhf.deb ... 63s Unpacking libsepol2:armhf (3.8.1-1) over (3.7-1) ... 63s Setting up libsepol2:armhf (3.8.1-1) ... 63s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 63s Preparing to unpack .../libnpth0t64_1.8-3_armhf.deb ... 63s Unpacking libnpth0t64:armhf (1.8-3) over (1.8-2) ... 63s Setting up libnpth0t64:armhf (1.8-3) ... 63s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 63s Preparing to unpack .../00-distro-info-data_0.64_all.deb ... 63s Unpacking distro-info-data (0.64) over (0.63) ... 64s Preparing to unpack .../01-iso-codes_4.18.0-1_all.deb ... 64s Unpacking iso-codes (4.18.0-1) over (4.17.0-1) ... 64s Preparing to unpack .../02-libbpf1_1%3a1.5.0-3_armhf.deb ... 64s Unpacking libbpf1:armhf (1:1.5.0-3) over (1:1.5.0-2) ... 64s Preparing to unpack .../03-libsqlite3-0_3.46.1-4_armhf.deb ... 64s Unpacking libsqlite3-0:armhf (3.46.1-4) over (3.46.1-3) ... 64s Preparing to unpack .../04-libunistring5_1.3-2_armhf.deb ... 64s Unpacking libunistring5:armhf (1.3-2) over (1.3-1) ... 64s Preparing to unpack .../05-ubuntu-pro-client-l10n_35.1ubuntu0_armhf.deb ... 64s Unpacking ubuntu-pro-client-l10n (35.1ubuntu0) over (35) ... 64s Preparing to unpack .../06-ubuntu-pro-client_35.1ubuntu0_armhf.deb ... 64s Unpacking ubuntu-pro-client (35.1ubuntu0) over (35) ... 64s Preparing to unpack .../07-ed_1.21.1-1_armhf.deb ... 64s Unpacking ed (1.21.1-1) over (1.21-1) ... 65s Preparing to unpack .../08-ethtool_1%3a6.14-2_armhf.deb ... 65s Unpacking ethtool (1:6.14-2) over (1:6.11-1) ... 65s Preparing to unpack .../09-libevdev2_1.13.4+dfsg-1_armhf.deb ... 65s Unpacking libevdev2:armhf (1.13.4+dfsg-1) over (1.13.3+dfsg-1) ... 65s Preparing to unpack .../10-libnftnl11_1.2.9-1_armhf.deb ... 65s Unpacking libnftnl11:armhf (1.2.9-1) over (1.2.8-1) ... 65s Preparing to unpack .../11-libnghttp2-14_1.64.0-1.1_armhf.deb ... 65s Unpacking libnghttp2-14:armhf (1.64.0-1.1) over (1.64.0-1ubuntu1) ... 65s Preparing to unpack .../12-libsensors-config_1%3a3.6.2-2_all.deb ... 65s Unpacking libsensors-config (1:3.6.2-2) over (1:3.6.0-10) ... 65s Preparing to unpack .../13-libsensors5_1%3a3.6.2-2_armhf.deb ... 65s Unpacking libsensors5:armhf (1:3.6.2-2) over (1:3.6.0-10) ... 65s Preparing to unpack .../14-liburcu8t64_0.15.2-2_armhf.deb ... 65s Unpacking liburcu8t64:armhf (0.15.2-2) over (0.15.1-1) ... 65s Preparing to unpack .../15-libusb-1.0-0_2%3a1.0.28-1_armhf.deb ... 65s Unpacking libusb-1.0-0:armhf (2:1.0.28-1) over (2:1.0.27-2) ... 65s Preparing to unpack .../16-man-db_2.13.1-1_armhf.deb ... 65s Unpacking man-db (2.13.1-1) over (2.13.0-1) ... 65s Preparing to unpack .../17-nano_8.4-1_armhf.deb ... 65s Unpacking nano (8.4-1) over (8.3-1) ... 65s Preparing to unpack .../18-publicsuffix_20250328.1952-0.1_all.deb ... 65s Unpacking publicsuffix (20250328.1952-0.1) over (20250108.1153-0.1) ... 65s Preparing to unpack .../19-usb.ids_2025.04.01-1_all.deb ... 65s Unpacking usb.ids (2025.04.01-1) over (2025.01.14-1) ... 65s Preparing to unpack .../20-usbutils_1%3a018-2_armhf.deb ... 65s Unpacking usbutils (1:018-2) over (1:018-1) ... 65s Preparing to unpack .../21-cloud-init-base_25.2~1g7a0265d3-0ubuntu1_all.deb ... 66s Unpacking cloud-init-base (25.2~1g7a0265d3-0ubuntu1) over (25.1.1-0ubuntu2) ... 66s Preparing to unpack .../22-dpkg-dev_1.22.18ubuntu3_all.deb ... 66s Unpacking dpkg-dev (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 66s Preparing to unpack .../23-libdpkg-perl_1.22.18ubuntu3_all.deb ... 66s Unpacking libdpkg-perl (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 66s Preparing to unpack .../24-patch_2.8-1_armhf.deb ... 66s Unpacking patch (2.8-1) over (2.7.6-7build3) ... 66s Preparing to unpack .../25-libjcat1_0.2.3-1_armhf.deb ... 66s Unpacking libjcat1:armhf (0.2.3-1) over (0.2.0-2build3) ... 66s Preparing to unpack .../26-fwupd_2.0.8-3_armhf.deb ... 66s Unpacking fwupd (2.0.8-3) over (2.0.7-1) ... 67s dpkg: warning: unable to delete old directory '/etc/grub.d': Directory not empty 67s Preparing to unpack .../27-libfwupd3_2.0.8-3_armhf.deb ... 67s Unpacking libfwupd3:armhf (2.0.8-3) over (2.0.7-1) ... 67s Preparing to unpack .../28-libmbim-proxy_1.32.0-1_armhf.deb ... 67s Unpacking libmbim-proxy (1.32.0-1) over (1.31.2-0ubuntu4) ... 67s Preparing to unpack .../29-libmbim-glib4_1.32.0-1_armhf.deb ... 67s Unpacking libmbim-glib4:armhf (1.32.0-1) over (1.31.2-0ubuntu4) ... 67s Preparing to unpack .../30-libmm-glib0_1.24.0-1_armhf.deb ... 67s Unpacking libmm-glib0:armhf (1.24.0-1) over (1.23.4-0ubuntu3) ... 67s Preparing to unpack .../31-libqmi-proxy_1.36.0-1_armhf.deb ... 67s Unpacking libqmi-proxy (1.36.0-1) over (1.35.6-1) ... 67s Preparing to unpack .../32-libqmi-glib5_1.36.0-1_armhf.deb ... 67s Unpacking libqmi-glib5:armhf (1.36.0-1) over (1.35.6-1) ... 67s Preparing to unpack .../33-htop_3.4.1-4_armhf.deb ... 67s Unpacking htop (3.4.1-4) over (3.4.0-2) ... 67s Preparing to unpack .../34-libftdi1-2_1.5-10_armhf.deb ... 67s Unpacking libftdi1-2:armhf (1.5-10) over (1.5-8build1) ... 67s Preparing to unpack .../35-libnvme1t64_1.13-2_armhf.deb ... 67s Unpacking libnvme1t64 (1.13-2) over (1.11.1-2) ... 67s Preparing to unpack .../36-python3-lazr.restfulclient_0.14.6-3_all.deb ... 67s Unpacking python3-lazr.restfulclient (0.14.6-3) over (0.14.6-2) ... 67s Preparing to unpack .../37-python3-more-itertools_10.7.0-1_all.deb ... 67s Unpacking python3-more-itertools (10.7.0-1) over (10.6.0-1) ... 67s Preparing to unpack .../38-python3-s3transfer_0.11.4-1_all.deb ... 67s Unpacking python3-s3transfer (0.11.4-1) over (0.11.2-2) ... 67s Preparing to unpack .../39-sos_4.9.1-1_all.deb ... 68s Unpacking sos (4.9.1-1) over (4.9.0-6) ... 68s Preparing to unpack .../40-cloud-init_25.2~1g7a0265d3-0ubuntu1_all.deb ... 68s Unpacking cloud-init (25.2~1g7a0265d3-0ubuntu1) over (25.1.1-0ubuntu2) ... 68s Setting up sos (4.9.1-1) ... 69s Setting up motd-news-config (13.7ubuntu1) ... 69s Setting up python3-more-itertools (10.7.0-1) ... 69s Setting up liburcu8t64:armhf (0.15.2-2) ... 69s Setting up distro-info-data (0.64) ... 69s Setting up htop (3.4.1-4) ... 69s Setting up libsqlite3-0:armhf (3.46.1-4) ... 69s Setting up python3-s3transfer (0.11.4-1) ... 69s Setting up libsensors-config (1:3.6.2-2) ... 69s Installing new version of config file /etc/sensors3.conf ... 69s Setting up libnghttp2-14:armhf (1.64.0-1.1) ... 69s Setting up libnftnl11:armhf (1.2.9-1) ... 69s Setting up man-db (2.13.1-1) ... 69s Updating database of manual pages ... 72s apparmor_parser: Unable to replace "/usr/bin/man". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 72s 72s man-db.service is a disabled or a static unit not running, not starting it. 72s Setting up cloud-init-base (25.2~1g7a0265d3-0ubuntu1) ... 74s Setting up libjcat1:armhf (0.2.3-1) ... 74s Setting up libnvme1t64 (1.13-2) ... 74s Setting up ed (1.21.1-1) ... 74s Setting up libunistring5:armhf (1.3-2) ... 74s Setting up patch (2.8-1) ... 74s Setting up usb.ids (2025.04.01-1) ... 74s Setting up libsensors5:armhf (1:3.6.2-2) ... 74s Setting up libdpkg-perl (1.22.18ubuntu3) ... 74s Setting up nano (8.4-1) ... 74s Installing new version of config file /etc/nanorc ... 74s Setting up libmm-glib0:armhf (1.24.0-1) ... 74s Setting up libusb-1.0-0:armhf (2:1.0.28-1) ... 74s Setting up python3-lazr.restfulclient (0.14.6-3) ... 74s Setting up libevdev2:armhf (1.13.4+dfsg-1) ... 74s Setting up publicsuffix (20250328.1952-0.1) ... 74s Setting up ubuntu-pro-client (35.1ubuntu0) ... 74s apparmor_parser: Unable to replace "ubuntu_pro_apt_news". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 74s 75s apparmor_parser: Unable to replace "apt_methods". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 75s 75s apparmor_parser: Unable to replace "ubuntu_pro_esm_cache". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 75s 76s Setting up iso-codes (4.18.0-1) ... 76s Setting up libbpf1:armhf (1:1.5.0-3) ... 76s Setting up libmbim-glib4:armhf (1.32.0-1) ... 76s Setting up ethtool (1:6.14-2) ... 76s Setting up ubuntu-pro-client-l10n (35.1ubuntu0) ... 76s Setting up cloud-init (25.2~1g7a0265d3-0ubuntu1) ... 76s Setting up libfwupd3:armhf (2.0.8-3) ... 76s Setting up libmbim-proxy (1.32.0-1) ... 76s Setting up usbutils (1:018-2) ... 76s Setting up dpkg-dev (1.22.18ubuntu3) ... 76s Setting up libftdi1-2:armhf (1.5-10) ... 76s Setting up libqmi-glib5:armhf (1.36.0-1) ... 76s Setting up libqmi-proxy (1.36.0-1) ... 76s Setting up fwupd (2.0.8-3) ... 77s fwupd-refresh.service is a disabled or a static unit not running, not starting it. 77s fwupd.service is a disabled or a static unit not running, not starting it. 77s Processing triggers for rsyslog (8.2412.0-2ubuntu2) ... 77s Processing triggers for plymouth-theme-ubuntu-text (24.004.60-2ubuntu7) ... 77s Processing triggers for dbus (1.16.2-2ubuntu1) ... 77s Processing triggers for install-info (7.1.1-1) ... 78s Processing triggers for libc-bin (2.41-6ubuntu1) ... 78s Processing triggers for initramfs-tools (0.147ubuntu1) ... 80s Reading package lists... 80s Building dependency tree... 80s Reading state information... 81s Starting pkgProblemResolver with broken count: 0 81s Starting 2 pkgProblemResolver with broken count: 0 81s Done 82s Solving dependencies... 83s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 85s autopkgtest [20:35:45]: rebooting testbed after setup commands that affected boot 125s autopkgtest [20:36:25]: testbed running kernel: Linux 6.8.0-58-generic #60~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 28 14:48:37 UTC 2 150s autopkgtest [20:36:50]: @@@@@@@@@@@@@@@@@@@@ apt-source asterisk 200s Get:1 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (dsc) [5416 B] 200s Get:2 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (tar) [11.3 kB] 200s Get:3 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (tar) [22.0 kB] 200s Get:4 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (tar) [22.6 kB] 200s Get:5 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (tar) [6402 kB] 200s Get:6 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (tar) [5977 kB] 200s Get:7 http://ftpmaster.internal/ubuntu questing/universe asterisk 1:22.2.0~dfsg+~cs6.15.60671435-2 (diff) [123 kB] 201s gpgv: Signature made Sat Feb 22 08:00:50 2025 UTC 201s gpgv: using RSA key 9FE3E9C36691A69FF53CC6842C7C3146C1A00121 201s gpgv: Can't check signature: No public key 201s dpkg-source: warning: cannot verify inline signature for ./asterisk_22.2.0~dfsg+~cs6.15.60671435-2.dsc: no acceptable signature found 202s autopkgtest [20:37:42]: testing package asterisk version 1:22.2.0~dfsg+~cs6.15.60671435-2 205s autopkgtest [20:37:45]: build not needed 213s autopkgtest [20:37:53]: test asttestmods: preparing testbed 214s Reading package lists... 215s Building dependency tree... 215s Reading state information... 215s Starting pkgProblemResolver with broken count: 0 216s Starting 2 pkgProblemResolver with broken count: 0 216s Done 217s The following NEW packages will be installed: 217s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 217s asterisk-modules asterisk-tests freetds-common libasound2-data libasound2t64 217s libb64-0d libc-client2007e libcodec2-1.2 libdeflate0 libevent-2.1-7t64 217s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libjbig0 217s libjpeg-turbo8 libjpeg8 libjwt2 liblerc4 libltdl7 liblua5.1-0 libneon27t64 217s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 217s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 217s libsharpyuv0 libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 217s libsrtp2-1 libsybdb5 libtiff6 libunbound8 liburiparser1 libvo-amrwbenc0 217s libvorbis0a libvorbisenc2 libvorbisfile3 libwebp7 libxml2-utils libxslt1.1 217s mlock 217s 0 upgraded, 58 newly installed, 0 to remove and 0 not upgraded. 217s Need to get 27.3 MB of archives. 217s After this operation, 82.7 MB of additional disk space will be used. 217s Get:1 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-config all 1:22.2.0~dfsg+~cs6.15.60671435-2 [226 kB] 218s Get:2 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 218s Get:3 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 218s Get:4 http://ftpmaster.internal/ubuntu questing/universe armhf mlock armhf 8:2007f~dfsg-7.1 [8214 B] 218s Get:5 http://ftpmaster.internal/ubuntu questing/universe armhf libc-client2007e armhf 8:2007f~dfsg-7.1 [604 kB] 218s Get:6 http://ftpmaster.internal/ubuntu questing/universe armhf libcodec2-1.2 armhf 1.2.0-3 [8250 kB] 219s Get:7 http://ftpmaster.internal/ubuntu questing/universe armhf libgmime-3.0-0t64 armhf 3.2.15+dfsg-1 [149 kB] 219s Get:8 http://ftpmaster.internal/ubuntu questing/universe armhf libgsm1 armhf 1.0.22-1build1 [24.8 kB] 219s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf libical3t64 armhf 3.0.20-1 [269 kB] 219s Get:10 http://ftpmaster.internal/ubuntu questing/universe armhf libiksemel3 armhf 1.4-4build2 [21.8 kB] 219s Get:11 http://ftpmaster.internal/ubuntu questing/main armhf libopus0 armhf 1.5.2-2 [2875 kB] 219s Get:12 http://ftpmaster.internal/ubuntu questing/main armhf libsamplerate0 armhf 0.2.2-4build1 [1341 kB] 219s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf libjack-jackd2-0 armhf 1.9.22~dfsg-4 [247 kB] 219s Get:14 http://ftpmaster.internal/ubuntu questing/universe armhf libb64-0d armhf 1.2-5build1 [9166 B] 219s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf libjwt2 armhf 1.17.2-1 [14.7 kB] 219s Get:16 http://ftpmaster.internal/ubuntu questing/universe armhf liblua5.1-0 armhf 5.1.5-11 [91.3 kB] 219s Get:17 http://ftpmaster.internal/ubuntu questing/universe armhf libneon27t64 armhf 0.34.2-1 [91.5 kB] 219s Get:18 http://ftpmaster.internal/ubuntu questing/main armhf libltdl7 armhf 2.5.4-4 [39.8 kB] 219s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf libodbc2 armhf 2.3.12-2ubuntu1 [145 kB] 219s Get:20 http://ftpmaster.internal/ubuntu questing/main armhf libogg0 armhf 1.3.5-3build1 [20.5 kB] 219s Get:21 http://ftpmaster.internal/ubuntu questing/universe armhf libopencore-amrnb0 armhf 0.1.6-1build1 [89.1 kB] 219s Get:22 http://ftpmaster.internal/ubuntu questing/universe armhf libopencore-amrwb0 armhf 0.1.6-1build1 [48.1 kB] 219s Get:23 http://ftpmaster.internal/ubuntu questing/universe armhf libopusenc0 armhf 0.2.1-2build1 [23.8 kB] 219s Get:24 http://ftpmaster.internal/ubuntu questing/universe armhf libopusfile0 armhf 0.12-4build3 [40.6 kB] 219s Get:25 http://ftpmaster.internal/ubuntu questing/main armhf libasound2-data all 1.2.13-1build1 [21.1 kB] 219s Get:26 http://ftpmaster.internal/ubuntu questing/main armhf libasound2t64 armhf 1.2.13-1build1 [347 kB] 220s Get:27 http://ftpmaster.internal/ubuntu questing/universe armhf libportaudio2 armhf 19.6.0-1.2build3 [60.9 kB] 220s Get:28 http://ftpmaster.internal/ubuntu questing/main armhf libpq5 armhf 17.4-1 [125 kB] 220s Get:29 http://ftpmaster.internal/ubuntu questing/universe armhf libradcli4 armhf 1.2.11-1build3 [37.5 kB] 220s Get:30 http://ftpmaster.internal/ubuntu questing/universe armhf libresample1 armhf 0.1.3-8 [7682 B] 220s Get:31 http://ftpmaster.internal/ubuntu questing/main armhf libsnmp-base all 5.9.4+dfsg-1.1ubuntu7 [206 kB] 220s Get:32 http://ftpmaster.internal/ubuntu questing/main armhf libsnmp40t64 armhf 5.9.4+dfsg-1.1ubuntu7 [1011 kB] 220s Get:33 http://ftpmaster.internal/ubuntu questing/main armhf libdeflate0 armhf 1.23-2 [38.7 kB] 220s Get:34 http://ftpmaster.internal/ubuntu questing/main armhf libjbig0 armhf 2.1-6.1ubuntu2 [24.9 kB] 220s Get:35 http://ftpmaster.internal/ubuntu questing/main armhf libjpeg-turbo8 armhf 2.1.5-3ubuntu2 [127 kB] 220s Get:36 http://ftpmaster.internal/ubuntu questing/main armhf libjpeg8 armhf 8c-2ubuntu11 [2148 B] 220s Get:37 http://ftpmaster.internal/ubuntu questing/main armhf liblerc4 armhf 4.0.0+ds-5ubuntu1 [160 kB] 220s Get:38 http://ftpmaster.internal/ubuntu questing/main armhf libsharpyuv0 armhf 1.5.0-0.1 [16.4 kB] 220s Get:39 http://ftpmaster.internal/ubuntu questing/main armhf libwebp7 armhf 1.5.0-0.1 [188 kB] 220s Get:40 http://ftpmaster.internal/ubuntu questing/main armhf libtiff6 armhf 4.7.0-3ubuntu1 [184 kB] 220s Get:41 http://ftpmaster.internal/ubuntu questing/universe armhf libspandsp2t64 armhf 0.0.6+dfsg-2.2 [268 kB] 220s Get:42 http://ftpmaster.internal/ubuntu questing/main armhf libspeex1 armhf 1.2.1-3 [49.0 kB] 220s Get:43 http://ftpmaster.internal/ubuntu questing/main armhf libspeexdsp1 armhf 1.2.1-3 [37.2 kB] 220s Get:44 http://ftpmaster.internal/ubuntu questing/universe armhf libsrtp2-1 armhf 2.7.0-3 [35.3 kB] 220s Get:45 http://ftpmaster.internal/ubuntu questing/main armhf freetds-common all 1.3.17+ds-2build3 [26.9 kB] 220s Get:46 http://ftpmaster.internal/ubuntu questing/main armhf libsybdb5 armhf 1.3.17+ds-2build3 [179 kB] 220s Get:47 http://ftpmaster.internal/ubuntu questing/main armhf libevent-2.1-7t64 armhf 2.1.12-stable-10 [127 kB] 220s Get:48 http://ftpmaster.internal/ubuntu questing/main armhf libunbound8 armhf 1.22.0-1ubuntu1 [423 kB] 220s Get:49 http://ftpmaster.internal/ubuntu questing/universe armhf libvo-amrwbenc0 armhf 0.1.3-2build1 [67.2 kB] 220s Get:50 http://ftpmaster.internal/ubuntu questing/main armhf libvorbis0a armhf 1.3.7-2 [86.7 kB] 220s Get:51 http://ftpmaster.internal/ubuntu questing/main armhf libvorbisenc2 armhf 1.3.7-2 [72.9 kB] 220s Get:52 http://ftpmaster.internal/ubuntu questing/main armhf libvorbisfile3 armhf 1.3.7-2 [16.2 kB] 220s Get:53 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-modules armhf 1:22.2.0~dfsg+~cs6.15.60671435-2 [3021 kB] 220s Get:54 http://ftpmaster.internal/ubuntu questing/universe armhf liburiparser1 armhf 0.9.8+dfsg-2 [30.3 kB] 220s Get:55 http://ftpmaster.internal/ubuntu questing/main armhf libxslt1.1 armhf 1.1.39-0exp1ubuntu4 [151 kB] 220s Get:56 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk armhf 1:22.2.0~dfsg+~cs6.15.60671435-2 [2454 kB] 220s Get:57 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-tests armhf 1:22.2.0~dfsg+~cs6.15.60671435-2 [599 kB] 220s Get:58 http://ftpmaster.internal/ubuntu questing/main armhf libxml2-utils armhf 2.12.7+dfsg+really2.9.14-0.4 [39.6 kB] 221s Fetched 27.3 MB in 3s (8734 kB/s) 221s Selecting previously unselected package asterisk-config. 221s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63964 files and directories currently installed.) 221s Preparing to unpack .../00-asterisk-config_1%3a22.2.0~dfsg+~cs6.15.60671435-2_all.deb ... 221s Unpacking asterisk-config (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 221s Selecting previously unselected package asterisk-core-sounds-en-gsm. 221s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 221s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 221s Selecting previously unselected package asterisk-core-sounds-en. 221s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 221s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 221s Selecting previously unselected package mlock. 221s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7.1_armhf.deb ... 221s Unpacking mlock (8:2007f~dfsg-7.1) ... 221s Selecting previously unselected package libc-client2007e. 221s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7.1_armhf.deb ... 221s Unpacking libc-client2007e (8:2007f~dfsg-7.1) ... 221s Selecting previously unselected package libcodec2-1.2:armhf. 221s Preparing to unpack .../05-libcodec2-1.2_1.2.0-3_armhf.deb ... 221s Unpacking libcodec2-1.2:armhf (1.2.0-3) ... 221s Selecting previously unselected package libgmime-3.0-0t64:armhf. 221s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.15+dfsg-1_armhf.deb ... 221s Unpacking libgmime-3.0-0t64:armhf (3.2.15+dfsg-1) ... 221s Selecting previously unselected package libgsm1:armhf. 221s Preparing to unpack .../07-libgsm1_1.0.22-1build1_armhf.deb ... 221s Unpacking libgsm1:armhf (1.0.22-1build1) ... 221s Selecting previously unselected package libical3t64:armhf. 222s Preparing to unpack .../08-libical3t64_3.0.20-1_armhf.deb ... 222s Unpacking libical3t64:armhf (3.0.20-1) ... 222s Selecting previously unselected package libiksemel3:armhf. 222s Preparing to unpack .../09-libiksemel3_1.4-4build2_armhf.deb ... 222s Unpacking libiksemel3:armhf (1.4-4build2) ... 222s Selecting previously unselected package libopus0:armhf. 222s Preparing to unpack .../10-libopus0_1.5.2-2_armhf.deb ... 222s Unpacking libopus0:armhf (1.5.2-2) ... 222s Selecting previously unselected package libsamplerate0:armhf. 222s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_armhf.deb ... 222s Unpacking libsamplerate0:armhf (0.2.2-4build1) ... 222s Selecting previously unselected package libjack-jackd2-0:armhf. 222s Preparing to unpack .../12-libjack-jackd2-0_1.9.22~dfsg-4_armhf.deb ... 222s Unpacking libjack-jackd2-0:armhf (1.9.22~dfsg-4) ... 222s Selecting previously unselected package libb64-0d:armhf. 222s Preparing to unpack .../13-libb64-0d_1.2-5build1_armhf.deb ... 222s Unpacking libb64-0d:armhf (1.2-5build1) ... 222s Selecting previously unselected package libjwt2:armhf. 222s Preparing to unpack .../14-libjwt2_1.17.2-1_armhf.deb ... 222s Unpacking libjwt2:armhf (1.17.2-1) ... 222s Selecting previously unselected package liblua5.1-0:armhf. 222s Preparing to unpack .../15-liblua5.1-0_5.1.5-11_armhf.deb ... 222s Unpacking liblua5.1-0:armhf (5.1.5-11) ... 222s Selecting previously unselected package libneon27t64:armhf. 222s Preparing to unpack .../16-libneon27t64_0.34.2-1_armhf.deb ... 222s Unpacking libneon27t64:armhf (0.34.2-1) ... 222s Selecting previously unselected package libltdl7:armhf. 222s Preparing to unpack .../17-libltdl7_2.5.4-4_armhf.deb ... 222s Unpacking libltdl7:armhf (2.5.4-4) ... 222s Selecting previously unselected package libodbc2:armhf. 222s Preparing to unpack .../18-libodbc2_2.3.12-2ubuntu1_armhf.deb ... 222s Unpacking libodbc2:armhf (2.3.12-2ubuntu1) ... 222s Selecting previously unselected package libogg0:armhf. 222s Preparing to unpack .../19-libogg0_1.3.5-3build1_armhf.deb ... 222s Unpacking libogg0:armhf (1.3.5-3build1) ... 222s Selecting previously unselected package libopencore-amrnb0:armhf. 222s Preparing to unpack .../20-libopencore-amrnb0_0.1.6-1build1_armhf.deb ... 222s Unpacking libopencore-amrnb0:armhf (0.1.6-1build1) ... 222s Selecting previously unselected package libopencore-amrwb0:armhf. 222s Preparing to unpack .../21-libopencore-amrwb0_0.1.6-1build1_armhf.deb ... 222s Unpacking libopencore-amrwb0:armhf (0.1.6-1build1) ... 222s Selecting previously unselected package libopusenc0:armhf. 222s Preparing to unpack .../22-libopusenc0_0.2.1-2build1_armhf.deb ... 222s Unpacking libopusenc0:armhf (0.2.1-2build1) ... 222s Selecting previously unselected package libopusfile0:armhf. 222s Preparing to unpack .../23-libopusfile0_0.12-4build3_armhf.deb ... 222s Unpacking libopusfile0:armhf (0.12-4build3) ... 222s Selecting previously unselected package libasound2-data. 222s Preparing to unpack .../24-libasound2-data_1.2.13-1build1_all.deb ... 222s Unpacking libasound2-data (1.2.13-1build1) ... 222s Selecting previously unselected package libasound2t64:armhf. 222s Preparing to unpack .../25-libasound2t64_1.2.13-1build1_armhf.deb ... 222s Unpacking libasound2t64:armhf (1.2.13-1build1) ... 222s Selecting previously unselected package libportaudio2:armhf. 222s Preparing to unpack .../26-libportaudio2_19.6.0-1.2build3_armhf.deb ... 222s Unpacking libportaudio2:armhf (19.6.0-1.2build3) ... 222s Selecting previously unselected package libpq5:armhf. 222s Preparing to unpack .../27-libpq5_17.4-1_armhf.deb ... 222s Unpacking libpq5:armhf (17.4-1) ... 222s Selecting previously unselected package libradcli4. 222s Preparing to unpack .../28-libradcli4_1.2.11-1build3_armhf.deb ... 222s Unpacking libradcli4 (1.2.11-1build3) ... 222s Selecting previously unselected package libresample1. 222s Preparing to unpack .../29-libresample1_0.1.3-8_armhf.deb ... 222s Unpacking libresample1 (0.1.3-8) ... 222s Selecting previously unselected package libsnmp-base. 223s Preparing to unpack .../30-libsnmp-base_5.9.4+dfsg-1.1ubuntu7_all.deb ... 223s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu7) ... 223s Selecting previously unselected package libsnmp40t64:armhf. 223s Preparing to unpack .../31-libsnmp40t64_5.9.4+dfsg-1.1ubuntu7_armhf.deb ... 223s Unpacking libsnmp40t64:armhf (5.9.4+dfsg-1.1ubuntu7) ... 223s Selecting previously unselected package libdeflate0:armhf. 223s Preparing to unpack .../32-libdeflate0_1.23-2_armhf.deb ... 223s Unpacking libdeflate0:armhf (1.23-2) ... 223s Selecting previously unselected package libjbig0:armhf. 223s Preparing to unpack .../33-libjbig0_2.1-6.1ubuntu2_armhf.deb ... 223s Unpacking libjbig0:armhf (2.1-6.1ubuntu2) ... 223s Selecting previously unselected package libjpeg-turbo8:armhf. 223s Preparing to unpack .../34-libjpeg-turbo8_2.1.5-3ubuntu2_armhf.deb ... 223s Unpacking libjpeg-turbo8:armhf (2.1.5-3ubuntu2) ... 223s Selecting previously unselected package libjpeg8:armhf. 223s Preparing to unpack .../35-libjpeg8_8c-2ubuntu11_armhf.deb ... 223s Unpacking libjpeg8:armhf (8c-2ubuntu11) ... 223s Selecting previously unselected package liblerc4:armhf. 223s Preparing to unpack .../36-liblerc4_4.0.0+ds-5ubuntu1_armhf.deb ... 223s Unpacking liblerc4:armhf (4.0.0+ds-5ubuntu1) ... 223s Selecting previously unselected package libsharpyuv0:armhf. 223s Preparing to unpack .../37-libsharpyuv0_1.5.0-0.1_armhf.deb ... 223s Unpacking libsharpyuv0:armhf (1.5.0-0.1) ... 223s Selecting previously unselected package libwebp7:armhf. 223s Preparing to unpack .../38-libwebp7_1.5.0-0.1_armhf.deb ... 223s Unpacking libwebp7:armhf (1.5.0-0.1) ... 223s Selecting previously unselected package libtiff6:armhf. 223s Preparing to unpack .../39-libtiff6_4.7.0-3ubuntu1_armhf.deb ... 223s Unpacking libtiff6:armhf (4.7.0-3ubuntu1) ... 223s Selecting previously unselected package libspandsp2t64:armhf. 223s Preparing to unpack .../40-libspandsp2t64_0.0.6+dfsg-2.2_armhf.deb ... 223s Unpacking libspandsp2t64:armhf (0.0.6+dfsg-2.2) ... 223s Selecting previously unselected package libspeex1:armhf. 223s Preparing to unpack .../41-libspeex1_1.2.1-3_armhf.deb ... 223s Unpacking libspeex1:armhf (1.2.1-3) ... 223s Selecting previously unselected package libspeexdsp1:armhf. 223s Preparing to unpack .../42-libspeexdsp1_1.2.1-3_armhf.deb ... 223s Unpacking libspeexdsp1:armhf (1.2.1-3) ... 223s Selecting previously unselected package libsrtp2-1:armhf. 223s Preparing to unpack .../43-libsrtp2-1_2.7.0-3_armhf.deb ... 223s Unpacking libsrtp2-1:armhf (2.7.0-3) ... 223s Selecting previously unselected package freetds-common. 223s Preparing to unpack .../44-freetds-common_1.3.17+ds-2build3_all.deb ... 223s Unpacking freetds-common (1.3.17+ds-2build3) ... 223s Selecting previously unselected package libsybdb5:armhf. 223s Preparing to unpack .../45-libsybdb5_1.3.17+ds-2build3_armhf.deb ... 223s Unpacking libsybdb5:armhf (1.3.17+ds-2build3) ... 223s Selecting previously unselected package libevent-2.1-7t64:armhf. 223s Preparing to unpack .../46-libevent-2.1-7t64_2.1.12-stable-10_armhf.deb ... 223s Unpacking libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 223s Selecting previously unselected package libunbound8:armhf. 223s Preparing to unpack .../47-libunbound8_1.22.0-1ubuntu1_armhf.deb ... 223s Unpacking libunbound8:armhf (1.22.0-1ubuntu1) ... 223s Selecting previously unselected package libvo-amrwbenc0:armhf. 223s Preparing to unpack .../48-libvo-amrwbenc0_0.1.3-2build1_armhf.deb ... 223s Unpacking libvo-amrwbenc0:armhf (0.1.3-2build1) ... 223s Selecting previously unselected package libvorbis0a:armhf. 223s Preparing to unpack .../49-libvorbis0a_1.3.7-2_armhf.deb ... 223s Unpacking libvorbis0a:armhf (1.3.7-2) ... 223s Selecting previously unselected package libvorbisenc2:armhf. 223s Preparing to unpack .../50-libvorbisenc2_1.3.7-2_armhf.deb ... 223s Unpacking libvorbisenc2:armhf (1.3.7-2) ... 223s Selecting previously unselected package libvorbisfile3:armhf. 223s Preparing to unpack .../51-libvorbisfile3_1.3.7-2_armhf.deb ... 224s Unpacking libvorbisfile3:armhf (1.3.7-2) ... 224s Selecting previously unselected package asterisk-modules. 224s Preparing to unpack .../52-asterisk-modules_1%3a22.2.0~dfsg+~cs6.15.60671435-2_armhf.deb ... 224s Unpacking asterisk-modules (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 224s Selecting previously unselected package liburiparser1:armhf. 224s Preparing to unpack .../53-liburiparser1_0.9.8+dfsg-2_armhf.deb ... 224s Unpacking liburiparser1:armhf (0.9.8+dfsg-2) ... 224s Selecting previously unselected package libxslt1.1:armhf. 224s Preparing to unpack .../54-libxslt1.1_1.1.39-0exp1ubuntu4_armhf.deb ... 224s Unpacking libxslt1.1:armhf (1.1.39-0exp1ubuntu4) ... 224s Selecting previously unselected package asterisk. 224s Preparing to unpack .../55-asterisk_1%3a22.2.0~dfsg+~cs6.15.60671435-2_armhf.deb ... 224s Unpacking asterisk (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 224s Selecting previously unselected package asterisk-tests. 224s Preparing to unpack .../56-asterisk-tests_1%3a22.2.0~dfsg+~cs6.15.60671435-2_armhf.deb ... 224s Unpacking asterisk-tests (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 224s Selecting previously unselected package libxml2-utils. 224s Preparing to unpack .../57-libxml2-utils_2.12.7+dfsg+really2.9.14-0.4_armhf.deb ... 224s Unpacking libxml2-utils (2.12.7+dfsg+really2.9.14-0.4) ... 224s Setting up libsharpyuv0:armhf (1.5.0-0.1) ... 224s Setting up libvo-amrwbenc0:armhf (0.1.3-2build1) ... 224s Setting up libneon27t64:armhf (0.34.2-1) ... 224s Setting up libogg0:armhf (1.3.5-3build1) ... 224s Setting up liblerc4:armhf (4.0.0+ds-5ubuntu1) ... 224s Setting up libspeex1:armhf (1.2.1-3) ... 224s Setting up libgsm1:armhf (1.0.22-1build1) ... 224s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 224s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu7) ... 224s Setting up libcodec2-1.2:armhf (1.2.0-3) ... 224s Setting up mlock (8:2007f~dfsg-7.1) ... 224s Setting up libsrtp2-1:armhf (2.7.0-3) ... 224s Setting up libpq5:armhf (17.4-1) ... 224s Setting up libdeflate0:armhf (1.23-2) ... 224s Setting up libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 224s Setting up libb64-0d:armhf (1.2-5build1) ... 224s Setting up libjwt2:armhf (1.17.2-1) ... 224s Setting up libjbig0:armhf (2.1-6.1ubuntu2) ... 224s Setting up libasound2-data (1.2.13-1build1) ... 224s Setting up libopencore-amrwb0:armhf (0.1.6-1build1) ... 224s Setting up libunbound8:armhf (1.22.0-1ubuntu1) ... 224s Setting up libasound2t64:armhf (1.2.13-1build1) ... 224s Setting up libradcli4 (1.2.11-1build3) ... 224s Setting up libopus0:armhf (1.5.2-2) ... 224s Setting up asterisk-config (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 225s Setting up libvorbis0a:armhf (1.3.7-2) ... 225s Setting up libical3t64:armhf (3.0.20-1) ... 225s Setting up libjpeg-turbo8:armhf (2.1.5-3ubuntu2) ... 225s Setting up libltdl7:armhf (2.5.4-4) ... 225s Setting up asterisk-core-sounds-en (1.6.1-1) ... 225s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 225s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en_US (asterisk-prompt-en-us) in auto mode 225s Setting up libwebp7:armhf (1.5.0-0.1) ... 225s Setting up libiksemel3:armhf (1.4-4build2) ... 225s Setting up libodbc2:armhf (2.3.12-2ubuntu1) ... 225s Setting up liburiparser1:armhf (0.9.8+dfsg-2) ... 225s Setting up libspeexdsp1:armhf (1.2.1-3) ... 225s Setting up liblua5.1-0:armhf (5.1.5-11) ... 225s Setting up libxslt1.1:armhf (1.1.39-0exp1ubuntu4) ... 225s Setting up libopencore-amrnb0:armhf (0.1.6-1build1) ... 225s Setting up libc-client2007e (8:2007f~dfsg-7.1) ... 225s Setting up libresample1 (0.1.3-8) ... 225s Setting up freetds-common (1.3.17+ds-2build3) ... 225s Setting up libxml2-utils (2.12.7+dfsg+really2.9.14-0.4) ... 225s Setting up libgmime-3.0-0t64:armhf (3.2.15+dfsg-1) ... 225s Setting up libsamplerate0:armhf (0.2.2-4build1) ... 225s Setting up libopusfile0:armhf (0.12-4build3) ... 225s Setting up libvorbisenc2:armhf (1.3.7-2) ... 225s Setting up libjpeg8:armhf (8c-2ubuntu11) ... 225s Setting up libopusenc0:armhf (0.2.1-2build1) ... 225s Setting up libsnmp40t64:armhf (5.9.4+dfsg-1.1ubuntu7) ... 225s Setting up libsybdb5:armhf (1.3.17+ds-2build3) ... 225s Setting up libvorbisfile3:armhf (1.3.7-2) ... 225s Setting up libjack-jackd2-0:armhf (1.9.22~dfsg-4) ... 225s Setting up libtiff6:armhf (4.7.0-3ubuntu1) ... 225s Setting up libportaudio2:armhf (19.6.0-1.2build3) ... 225s Setting up libspandsp2t64:armhf (0.0.6+dfsg-2.2) ... 225s Setting up asterisk-modules (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 225s Setting up asterisk (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 225s Adding system user for Asterisk 225s info: Adding user `asterisk' to group `dialout' ... 225s info: Adding user `asterisk' to group `audio' ... 226s Created symlink '/etc/systemd/system/multi-user.target.wants/asterisk.service' → '/usr/lib/systemd/system/asterisk.service'. 228s Setting up asterisk-tests (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 228s Processing triggers for libc-bin (2.41-6ubuntu1) ... 228s Processing triggers for man-db (2.13.1-1) ... 238s autopkgtest [20:38:18]: test asttestmods: [----------------------- 240s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 242s 'U' option is not compatible with remote console mode and has no effect. 242s 242s Asterisk has fully booted. 242s 'U' option is not compatible with remote console mode and has no effect. 242s 242s Running all available tests... 242s 242s START /apps/app_gosub/ - gosub application 242s END /apps/app_gosub/ - gosub application Time: <1ms Result: PASS 242s START /apps/app_voicemail/ - test_voicemail_vm_info 242s END /apps/app_voicemail/ - test_voicemail_vm_info Time: <1ms Result: PASS 242s START /apps/app_voicemail/ - test_voicemail_load_config 242s END /apps/app_voicemail/ - test_voicemail_load_config Time: <1ms Result: PASS 242s START /apps/app_voicemail/ - test_voicemail_notify_endl 242s END /apps/app_voicemail/ - test_voicemail_notify_endl Time: 5ms Result: PASS 242s START /apps/app_voicemail/ - vmuser 242s END /apps/app_voicemail/ - vmuser Time: <1ms Result: PASS 242s START /apps/app_voicemail/ - test_voicemail_msgcount 242s END /apps/app_voicemail/ - test_voicemail_msgcount Time: 79ms Result: PASS 242s START /apps/app_voicemail/ - vmsayname_exec 242s [app_voicemail.c:test_voicemail_vmsayname:15733]: Test playing of extension when greeting is not available... 247s [app_voicemail.c:test_voicemail_vmsayname:15754]: Test playing created mailbox greeting... 251s END /apps/app_voicemail/ - vmsayname_exec Time: 8887ms Result: PASS 251s START /ari/validators/ - validate_list 251s END /ari/validators/ - validate_list Time: <1ms Result: PASS 251s START /ari/validators/ - validate_date 251s END /ari/validators/ - validate_date Time: <1ms Result: PASS 251s START /ari/validators/ - validate_string 251s END /ari/validators/ - validate_string Time: <1ms Result: PASS 251s START /ari/validators/ - validate_long 251s END /ari/validators/ - validate_long Time: <1ms Result: PASS 251s START /ari/validators/ - validate_int 251s END /ari/validators/ - validate_int Time: <1ms Result: PASS 251s START /ari/validators/ - validate_boolean 251s END /ari/validators/ - validate_boolean Time: <1ms Result: PASS 251s START /ari/validators/ - validate_byte 251s END /ari/validators/ - validate_byte Time: <1ms Result: PASS 251s START /bridges/bridge_softmix/ - sfu_remove_destination_streams 251s END /bridges/bridge_softmix/ - sfu_remove_destination_streams Time: <1ms Result: PASS 251s START /bridges/bridge_softmix/ - sfu_append_source_streams 251s END /bridges/bridge_softmix/ - sfu_append_source_streams Time: <1ms Result: PASS 251s START /channels/features/ - test_features_channel_interval 254s END /channels/features/ - test_features_channel_interval Time: 3003ms Result: PASS 254s START /channels/features/ - test_features_channel_dtmf 256s END /channels/features/ - test_features_channel_dtmf Time: 2014ms Result: PASS 256s START /config/ - config_options_test 256s END /config/ - config_options_test Time: <1ms Result: PASS 256s START /config/ - ast_parse_arg 256s END /config/ - ast_parse_arg Time: <1ms Result: PASS 256s START /core/endpoints/ - setters 256s END /core/endpoints/ - setters Time: <1ms Result: PASS 256s START /core/endpoints/ - defaults 256s END /core/endpoints/ - defaults Time: <1ms Result: PASS 256s START /core/endpoints/ - create 256s END /core/endpoints/ - create Time: <1ms Result: PASS 256s START /funcs/func_curl/ - vulnerable_url 256s END /funcs/func_curl/ - vulnerable_url Time: <1ms Result: PASS 256s START /funcs/func_env/ - func_file 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=a'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=a'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=a'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,1)=b'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,1)=b'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,-3)=b'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,-3)=b'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2)=c'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,2)=c'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-7)=c'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-7)=c'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,2)=d'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,2)=d'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,-3)=d'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,-3)=d'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)=e'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)=e'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=fg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=fg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=fg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=fg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,)=h'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,,)=h'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,l)=h'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,ld)=h'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abc'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=ab'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefg'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefghijklmnop'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,2,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-1,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,3,0,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,la)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,ld)='... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,10)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 256s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=a'... OK! 256s END /funcs/func_env/ - func_file Time: 17ms Result: PASS 256s START /funcs/func_json/ - func_JSON_DECODE 256s END /funcs/func_json/ - func_JSON_DECODE Time: <1ms Result: PASS 256s START /funcs/func_presence/ - test_presence_state_base64_encode 256s END /funcs/func_presence/ - test_presence_state_base64_encode Time: 20ms Result: PASS 256s START /funcs/func_presence/ - test_presence_state_change 256s END /funcs/func_presence/ - test_presence_state_change Time: <1ms Result: PASS 256s START /funcs/func_presence/ - parse_invalid_presence_data 256s END /funcs/func_presence/ - parse_invalid_presence_data Time: <1ms Result: PASS 256s START /funcs/func_presence/ - parse_valid_presence_data 256s END /funcs/func_presence/ - parse_valid_presence_data Time: <1ms Result: PASS 256s START /funcs/func_sayfiles/ - test_SAYFILES_function 256s [func_sayfiles.c:test_SAYFILES_function:179]: Testing SAYFILES() substitution ... 256s END /funcs/func_sayfiles/ - test_SAYFILES_function Time: 7ms Result: PASS 256s START /funcs/func_strings/ - func_TRIM 256s END /funcs/func_strings/ - func_TRIM Time: <1ms Result: PASS 256s START /funcs/func_strings/ - func_STRBETWEEN 256s END /funcs/func_strings/ - func_STRBETWEEN Time: <1ms Result: PASS 256s START /funcs/func_strings/ - func_STRREPLACE_test 256s END /funcs/func_strings/ - func_STRREPLACE_test Time: <1ms Result: PASS 256s START /funcs/func_strings/ - func_FILTER_test 256s END /funcs/func_strings/ - func_FILTER_test Time: <1ms Result: PASS 256s START /funcs/func_strings/ - func_REPLACE_test 256s END /funcs/func_strings/ - func_REPLACE_test Time: <1ms Result: PASS 256s START /funcs/func_strings/ - func_FIELDNUM_test 256s END /funcs/func_strings/ - func_FIELDNUM_test Time: <1ms Result: PASS 256s START /geoloc/ - create_from_pidf 256s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1274]: ID: 'point-2d' pidf_element: 'tuple' format: 'GML' method: 'Manual' 256s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1286]: location_vars expected: shape=Point,crs=2d,pos=-34.410649 150.87651 256s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1287]: location_vars received: shape=Point,crs=2d,pos=-34.410649 150.87651 256s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1293]: usage_rules expected: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 256s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1294]: usage_rules received: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 256s END /geoloc/ - create_from_pidf Time: <1ms Result: PASS 256s START /geoloc/ - create_from_uri 256s END /geoloc/ - create_from_uri Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order 256s [test_abstract_jb.c:AST_JB_FIXED_put_out_of_order:531]: Executing AST_JB_FIXED_put_out_of_order... 256s END /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_FIXED_put_overflow 256s [test_abstract_jb.c:AST_JB_FIXED_put_overflow:529]: Executing AST_JB_FIXED_put_overflow... 256s END /main/abstract_jb/ - AST_JB_FIXED_put_overflow Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_FIXED_put 256s [test_abstract_jb.c:AST_JB_FIXED_put:527]: Executing AST_JB_FIXED_put... 256s END /main/abstract_jb/ - AST_JB_FIXED_put Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_FIXED_put_first 256s [test_abstract_jb.c:AST_JB_FIXED_put_first:525]: Executing AST_JB_FIXED_create... 256s END /main/abstract_jb/ - AST_JB_FIXED_put_first Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_FIXED_create 256s [test_abstract_jb.c:AST_JB_FIXED_create:523]: Executing AST_JB_FIXED_create... 256s END /main/abstract_jb/ - AST_JB_FIXED_create Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order 256s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_out_of_order:521]: Executing AST_JB_ADAPTIVE_put_out_of_order... 256s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow 256s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_overflow:519]: Executing AST_JB_ADAPTIVE_put_overflow... 256s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put 256s [test_abstract_jb.c:AST_JB_ADAPTIVE_put:517]: Executing AST_JB_ADAPTIVE_put... 256s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first 256s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_first:515]: Executing AST_JB_ADAPTIVE_create... 256s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first Time: <1ms Result: PASS 256s START /main/abstract_jb/ - AST_JB_ADAPTIVE_create 256s [test_abstract_jb.c:AST_JB_ADAPTIVE_create:513]: Executing AST_JB_ADAPTIVE_create... 256s END /main/abstract_jb/ - AST_JB_ADAPTIVE_create Time: <1ms Result: PASS 256s START /main/acl/ - acl 256s END /main/acl/ - acl Time: <1ms Result: PASS 256s START /main/acl/ - invalid_acl 256s END /main/acl/ - invalid_acl Time: <1ms Result: PASS 256s START /main/amihooks/ - amihook_cli_send 256s END /main/amihooks/ - amihook_cli_send Time: <1ms Result: PASS 256s START /main/aoc/ - aoc_event_test 256s END /main/aoc/ - aoc_event_test Time: <1ms Result: PASS 256s START /main/aoc/ - aoc_encode_decode_test 256s END /main/aoc/ - aoc_encode_decode_test Time: <1ms Result: PASS 256s START /main/app/ - options_parsing 256s END /main/app/ - options_parsing Time: <1ms Result: PASS 256s START /main/app/ - app_group 256s [test_app.c:app_group:172]: Creating test channels with the following groups: 256s 'a groupgroupgroup', 'a groupGroupgroup', 'a group@a_category', 'a group@another!Category' 256s [test_app.c:app_group:211]: (Subtest 1) Found 4 matches as expected when examining group:'gr' category:'' 256s [test_app.c:app_group:211]: (Subtest 2) Found 1 matches as expected when examining group:'(group){2}$' category:'' 256s [test_app.c:app_group:211]: (Subtest 3) Found 4 matches as expected when examining group:'[:ascii:]' category:'' 256s [test_app.c:app_group:211]: (Subtest 4) Found 0 matches as expected when examining group:'^(NOMATCH)' category:'' 256s [test_app.c:app_group:211]: (Subtest 5) Found 2 matches as expected when examining group:'a group' category:'(gory)$' 256s [test_app.c:app_group:211]: (Subtest 6) Found 1 matches as expected when examining group:'a group' category:'[A-Z]+' 256s [test_app.c:app_group:211]: (Subtest 7) Found 0 matches as expected when examining group:'a group' category:'[[' 256s END /main/app/ - app_group Time: <1ms Result: PASS 256s START /main/ast_expr/ - expr_test 256s END /main/ast_expr/ - expr_test Time: <1ms Result: PASS 256s START /main/astdb/ - put_get_long 256s END /main/astdb/ - put_get_long Time: 143ms Result: PASS 256s START /main/astdb/ - perftest 257s END /main/astdb/ - perftest Time: 355ms Result: PASS 257s START /main/astdb/ - gettree_deltree 257s END /main/astdb/ - gettree_deltree Time: <1ms Result: PASS 257s START /main/astdb/ - put_get_del 257s END /main/astdb/ - put_get_del Time: <1ms Result: PASS 257s START /main/astobj2/ - astobj2_weak_container 257s END /main/astobj2/ - astobj2_weak_container Time: <1ms Result: PASS 257s START /main/astobj2/ - astobj2_weak1 257s END /main/astobj2/ - astobj2_weak1 Time: <1ms Result: PASS 257s START /main/astobj2/ - thrash 257s [test_astobj2_thrash.c:hash_test:266]: Executing hash concurrency test... 257s END /main/astobj2/ - thrash Time: 152ms Result: PASS 257s START /main/astobj2/ - astobj2_test4 257s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 1, List containers. 257s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 2, Hash containers. 257s [test_astobj2.c:test_traversal_sorted:1615]: Test 3, List containers. 257s [test_astobj2.c:test_traversal_sorted:1615]: Test 4, Hash containers. 257s [test_astobj2.c:test_traversal_sorted:1615]: Test 5, RBTree containers. 257s END /main/astobj2/ - astobj2_test4 Time: <1ms Result: PASS 257s START /main/astobj2/ - astobj2_test3 257s END /main/astobj2/ - astobj2_test3 Time: <1ms Result: PASS 257s START /main/astobj2/ - astobj2_test2 257s END /main/astobj2/ - astobj2_test2 Time: <1ms Result: PASS 257s START /main/astobj2/ - astobj2_test1 257s [test_astobj2.c:astobj2_test_1_helper:434]: Test 1, List containers (non-sorted). 257s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 257s [test_astobj2.c:astobj2_test_1_helper:434]: Test 2, List containers (sorted). 257s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 257s [test_astobj2.c:astobj2_test_1_helper:434]: Test 3, Hash containers (non-sorted). 257s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 52, items: 1000 257s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, Hash containers (sorted). 257s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 237, items: 1000 257s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, RBTree containers (sorted). 257s [test_astobj2.c:astobj2_test_1_helper:488]: RBTree container created: buckets: 1, items: 1000 257s END /main/astobj2/ - astobj2_test1 Time: 13ms Result: PASS 257s START /main/astobj2/perf/ - astobj2_test_perf 258s [test_astobj2.c:testloop:2001]: 20.00K traversals, List 259s [test_astobj2.c:testloop:2001]: 40.00K traversals, List 260s [test_astobj2.c:testloop:2001]: 60.00K traversals, List 261s [test_astobj2.c:testloop:2001]: 80.00K traversals, List 262s [test_astobj2.c:testloop:2006]: 100.00K traversals, List : 4897 ms 262s [test_astobj2.c:testloop:2001]: 20.00K traversals, Hash 263s [test_astobj2.c:testloop:2001]: 40.00K traversals, Hash 264s [test_astobj2.c:testloop:2001]: 60.00K traversals, Hash 264s [test_astobj2.c:testloop:2001]: 80.00K traversals, Hash 265s [test_astobj2.c:testloop:2006]: 100.00K traversals, Hash : 3222 ms 266s [test_astobj2.c:testloop:2001]: 20.00K traversals, RBTree 266s [test_astobj2.c:testloop:2001]: 40.00K traversals, RBTree 267s [test_astobj2.c:testloop:2001]: 60.00K traversals, RBTree 268s [test_astobj2.c:testloop:2001]: 80.00K traversals, RBTree 269s [test_astobj2.c:testloop:2006]: 100.00K traversals, RBTree : 3823 ms 269s END /main/astobj2/perf/ - astobj2_test_perf Time: 11943ms Result: PASS 269s START /main/bridging/ - test_bridging_deferred_queue 270s END /main/bridging/ - test_bridging_deferred_queue Time: 1012ms Result: PASS 270s START /main/bucket/ - bucket_file_json 270s END /main/bucket/ - bucket_file_json Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_metadata_get 270s END /main/bucket/ - bucket_file_metadata_get Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_metadata_unset 270s END /main/bucket/ - bucket_file_metadata_unset Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_metadata_set 270s END /main/bucket/ - bucket_file_metadata_set Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_is_stale 270s END /main/bucket/ - bucket_file_is_stale Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_delete 270s END /main/bucket/ - bucket_file_delete Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_update 270s END /main/bucket/ - bucket_file_update Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_retrieve 270s END /main/bucket/ - bucket_file_retrieve Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_copy 270s END /main/bucket/ - bucket_file_copy Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_clone 270s END /main/bucket/ - bucket_file_clone Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_create 270s END /main/bucket/ - bucket_file_create Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_file_alloc 270s END /main/bucket/ - bucket_file_alloc Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_json 270s END /main/bucket/ - bucket_json Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_is_stale 270s END /main/bucket/ - bucket_is_stale Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_retrieve 270s END /main/bucket/ - bucket_retrieve Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_delete 270s END /main/bucket/ - bucket_delete Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_clone 270s END /main/bucket/ - bucket_clone Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_create 270s END /main/bucket/ - bucket_create Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_alloc 270s END /main/bucket/ - bucket_alloc Time: <1ms Result: PASS 270s START /main/bucket/ - bucket_scheme_register_unregister 270s END /main/bucket/ - bucket_scheme_register_unregister Time: <1ms Result: PASS 270s START /main/callerid/ - parse_off_nominal 270s END /main/callerid/ - parse_off_nominal Time: <1ms Result: PASS 270s START /main/callerid/ - parse_nominal 270s END /main/callerid/ - parse_nominal Time: <1ms Result: PASS 270s START /main/cdr/ - test_cdr_fork_cdr 272s Verifying expected record CDRTestChannel/Alice, 272s Finished expected record CDRTestChannel/Alice, 272s Verifying expected record CDRTestChannel/Alice, 272s Finished expected record CDRTestChannel/Alice, 272s Verifying expected record CDRTestChannel/Alice, 272s Finished expected record CDRTestChannel/Alice, 272s END /main/cdr/ - test_cdr_fork_cdr Time: 2001ms Result: PASS 272s START /main/cdr/ - test_cdr_no_reset_cdr 273s Verifying expected record CDRTestChannel/Alice, 273s Finished expected record CDRTestChannel/Alice, 273s END /main/cdr/ - test_cdr_no_reset_cdr Time: 1000ms Result: PASS 273s START /main/cdr/ - test_cdr_fields 275s Verifying expected record CDRTestChannel/Alice, 275s Finished expected record CDRTestChannel/Alice, 275s Verifying expected record CDRTestChannel/Alice, 275s Finished expected record CDRTestChannel/Alice, 275s Verifying expected record CDRTestChannel/Alice, 275s Finished expected record CDRTestChannel/Alice, 275s END /main/cdr/ - test_cdr_fields Time: 2000ms Result: PASS 275s START /main/cdr/ - test_cdr_park 278s Verifying expected record CDRTestChannel/Alice, 278s Finished expected record CDRTestChannel/Alice, 278s Verifying expected record CDRTestChannel/Bob, 278s Finished expected record CDRTestChannel/Bob, 278s END /main/cdr/ - test_cdr_park Time: 3002ms Result: PASS 278s START /main/cdr/ - test_cdr_dial_answer_multiparty 283s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 283s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 283s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 283s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 283s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 283s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 283s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/David 283s Finished expected record CDRTestChannel/Bob, CDRTestChannel/David 283s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/David 283s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/David 283s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 283s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 283s END /main/cdr/ - test_cdr_dial_answer_multiparty Time: 5005ms Result: PASS 283s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b 286s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 286s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 286s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b Time: 3002ms Result: PASS 286s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a Time: 2004ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_answer_no_bridge 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Verifying expected record CDRTestChannel/Alice, 288s Finished expected record CDRTestChannel/Alice, 288s Verifying expected record CDRTestChannel/Bob, 288s Finished expected record CDRTestChannel/Bob, 288s END /main/cdr/ - test_cdr_dial_answer_no_bridge Time: 1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_parallel_failed 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 288s END /main/cdr/ - test_cdr_dial_parallel_failed Time: <1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_caller_cancel 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_caller_cancel Time: <1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_unavailable 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_unavailable Time: <1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_busy 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_busy Time: <1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_congestion 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_congestion Time: 1ms Result: PASS 288s START /main/cdr/ - test_cdr_dial_unanswered 288s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 288s END /main/cdr/ - test_cdr_dial_unanswered Time: <1ms Result: PASS 288s START /main/cdr/ - test_cdr_outbound_bridged_call 291s Verifying expected record CDRTestChannel/Bob, 291s Finished expected record CDRTestChannel/Bob, 291s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 291s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 291s END /main/cdr/ - test_cdr_outbound_bridged_call Time: 3003ms Result: PASS 291s START /main/cdr/ - test_cdr_single_multiparty_bridge 295s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 295s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 295s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 295s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 295s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 295s Finished expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 295s Verifying expected record CDRTestChannel/Charlie, 295s Finished expected record CDRTestChannel/Charlie, 295s END /main/cdr/ - test_cdr_single_multiparty_bridge Time: 4003ms Result: PASS 295s START /main/cdr/ - test_cdr_single_twoparty_bridge_b 298s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 298s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 298s Verifying expected record CDRTestChannel/Bob, 298s Finished expected record CDRTestChannel/Bob, 298s END /main/cdr/ - test_cdr_single_twoparty_bridge_b Time: 3002ms Result: PASS 298s START /main/cdr/ - test_cdr_single_twoparty_bridge_a 300s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 300s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 300s Verifying expected record CDRTestChannel/Bob, 300s Finished expected record CDRTestChannel/Bob, 300s END /main/cdr/ - test_cdr_single_twoparty_bridge_a Time: 2002ms Result: PASS 300s START /main/cdr/ - test_cdr_single_bridge_continue 302s Verifying expected record CDRTestChannel/Alice, 302s Finished expected record CDRTestChannel/Alice, 302s Verifying expected record CDRTestChannel/Alice, 302s Finished expected record CDRTestChannel/Alice, 302s END /main/cdr/ - test_cdr_single_bridge_continue Time: 2001ms Result: PASS 302s START /main/cdr/ - test_cdr_single_bridge 304s Verifying expected record CDRTestChannel/Alice, 304s Finished expected record CDRTestChannel/Alice, 304s END /main/cdr/ - test_cdr_single_bridge Time: 2001ms Result: PASS 304s START /main/cdr/ - test_cdr_single_party 304s Verifying expected record CDRTestChannel/Alice, 304s Finished expected record CDRTestChannel/Alice, 304s END /main/cdr/ - test_cdr_single_party Time: <1ms Result: PASS 304s START /main/cdr/ - test_cdr_unanswered_outbound_call 304s Verifying expected record CDRTestChannel/Alice, 304s Finished expected record CDRTestChannel/Alice, 304s END /main/cdr/ - test_cdr_unanswered_outbound_call Time: <1ms Result: PASS 304s START /main/cdr/ - test_cdr_unanswered_inbound_call 304s Verifying expected record CDRTestChannel/Alice, 304s Finished expected record CDRTestChannel/Alice, 304s END /main/cdr/ - test_cdr_unanswered_inbound_call Time: <1ms Result: PASS 304s START /main/cdr/ - test_cdr_channel_creation 304s Verifying expected record CDRTestChannel/Alice, 304s Finished expected record CDRTestChannel/Alice, 304s END /main/cdr/ - test_cdr_channel_creation Time: <1ms Result: PASS 304s START /main/channel/ - add_fd 304s END /main/channel/ - add_fd Time: <1ms Result: PASS 304s START /main/channel/ - set_fd_grow 304s END /main/channel/ - set_fd_grow Time: <1ms Result: PASS 304s START /main/config/ - variable_list_from_quoted_string 304s END /main/config/ - variable_list_from_quoted_string Time: <1ms Result: PASS 304s START /main/config/ - variable_list_join_replace 304s END /main/config/ - variable_list_join_replace Time: <1ms Result: PASS 304s START /main/config/ - variable_lists_match 304s END /main/config/ - variable_lists_match Time: <1ms Result: PASS 304s START /main/config/ - config_dialplan_function 304s END /main/config/ - config_dialplan_function Time: <1ms Result: PASS 304s START /main/config/ - config_hook 304s END /main/config/ - config_hook Time: <1ms Result: PASS 304s START /main/config/ - copy_config 304s END /main/config/ - copy_config Time: <1ms Result: PASS 304s START /main/config/ - config_template_ops 304s END /main/config/ - config_template_ops Time: <1ms Result: PASS 304s START /main/config/ - config_filtered_ops 304s END /main/config/ - config_filtered_ops Time: <1ms Result: PASS 304s START /main/config/ - config_basic_ops 304s END /main/config/ - config_basic_ops Time: <1ms Result: PASS 304s START /main/config/ - config_save 304s END /main/config/ - config_save Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_umax 304s END /main/conversions/ - str_to_umax Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_imax 304s END /main/conversions/ - str_to_imax Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_ulong 304s END /main/conversions/ - str_to_ulong Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_long 304s END /main/conversions/ - str_to_long Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_uint 304s END /main/conversions/ - str_to_uint Time: <1ms Result: PASS 304s START /main/conversions/ - str_to_int 304s END /main/conversions/ - str_to_int Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_get_unknown 304s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_get_unknown 304s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_get_unregistered 304s END /main/core_codec/ - codec_get_unregistered Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_get 304s END /main/core_codec/ - codec_get Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_register_audio_no_sample_rate 304s END /main/core_codec/ - codec_register_audio_no_sample_rate Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_register_unknown 304s END /main/core_codec/ - codec_register_unknown Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_register_twice 304s END /main/core_codec/ - codec_register_twice Time: <1ms Result: PASS 304s START /main/core_codec/ - codec_register 304s END /main/core_codec/ - codec_register Time: <1ms Result: PASS 304s START /main/core_format/ - format_parse_and_generate_sdp_fmtp 304s END /main/core_format/ - format_parse_and_generate_sdp_fmtp Time: <1ms Result: PASS 304s START /main/core_format/ - format_parse_sdp_fmtp_without_interface 304s END /main/core_format/ - format_parse_sdp_fmtp_without_interface Time: <1ms Result: PASS 304s START /main/core_format/ - format_attribute_get_without_interface 304s END /main/core_format/ - format_attribute_get_without_interface Time: <1ms Result: PASS 304s START /main/core_format/ - format_attribute_set_without_interface 304s END /main/core_format/ - format_attribute_set_without_interface Time: <1ms Result: PASS 304s START /main/core_format/ - format_copy 304s END /main/core_format/ - format_copy Time: <1ms Result: PASS 304s START /main/core_format/ - format_joint_different_codec 304s END /main/core_format/ - format_joint_different_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_attr_joint_same_codec 304s END /main/core_format/ - format_attr_joint_same_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_joint_same_codec 304s END /main/core_format/ - format_joint_same_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_cmp_different_codec 304s END /main/core_format/ - format_cmp_different_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_attr_cmp_same_codec 304s END /main/core_format/ - format_attr_cmp_same_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_cmp_same_codec 304s END /main/core_format/ - format_cmp_same_codec Time: <1ms Result: PASS 304s START /main/core_format/ - format_clone 304s END /main/core_format/ - format_clone Time: <1ms Result: PASS 304s START /main/core_format/ - format_retrieve_attr 304s END /main/core_format/ - format_retrieve_attr Time: <1ms Result: PASS 304s START /main/core_format/ - format_create_attr 304s END /main/core_format/ - format_create_attr Time: <1ms Result: PASS 304s START /main/core_format/ - format_create 304s END /main/core_format/ - format_create Time: <1ms Result: PASS 304s START /main/data_buffer/ - buffer_nominal 304s END /main/data_buffer/ - buffer_nominal Time: <1ms Result: PASS 304s START /main/data_buffer/ - buffer_resize 304s END /main/data_buffer/ - buffer_resize Time: <1ms Result: PASS 304s START /main/data_buffer/ - buffer_put 304s END /main/data_buffer/ - buffer_put Time: <1ms Result: PASS 304s START /main/data_buffer/ - buffer_create 304s END /main/data_buffer/ - buffer_create Time: <1ms Result: PASS 304s START /main/devicestate/ - devstate_channels 304s END /main/devicestate/ - devstate_channels Time: <1ms Result: PASS 304s START /main/devicestate/ - devstate_conversions 304s END /main/devicestate/ - devstate_conversions Time: <1ms Result: PASS 304s START /main/devicestate/ - devstate_changed 304s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 304s [test_devicestate.c:devstate_changed:716]: Testing update 0: actual is 1; expected is 1 304s [test_devicestate.c:devstate_changed:716]: Testing update 1: actual is 2; expected is 2 304s [test_devicestate.c:devstate_changed:716]: Testing update 2: actual is 3; expected is 3 304s [test_devicestate.c:devstate_changed:716]: Testing update 3: actual is 4; expected is 4 304s [test_devicestate.c:devstate_changed:716]: Testing update 4: actual is 5; expected is 5 304s [test_devicestate.c:devstate_changed:716]: Testing update 5: actual is 6; expected is 6 304s [test_devicestate.c:devstate_changed:716]: Testing update 6: actual is 7; expected is 7 304s [test_devicestate.c:devstate_changed:716]: Testing update 7: actual is 8; expected is 8 304s [test_devicestate.c:wait_for_device_state_updates:308]: Received 1 of 1 updates 304s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 304s [test_devicestate.c:devstate_changed:754]: Testing update 0: actual is 1; expected is 1 304s [test_devicestate.c:devstate_changed:754]: Testing update 1: actual is 2; expected is 2 304s [test_devicestate.c:devstate_changed:754]: Testing update 2: actual is 3; expected is 3 304s [test_devicestate.c:devstate_changed:754]: Testing update 3: actual is 4; expected is 4 304s [test_devicestate.c:devstate_changed:754]: Testing update 4: actual is 5; expected is 5 304s [test_devicestate.c:devstate_changed:754]: Testing update 5: actual is 6; expected is 6 304s [test_devicestate.c:devstate_changed:754]: Testing update 6: actual is 7; expected is 7 304s [test_devicestate.c:devstate_changed:754]: Testing update 7: actual is 8; expected is 8 304s END /main/devicestate/ - devstate_changed Time: 1ms Result: PASS 304s START /main/devicestate/ - devstate_prov_del 304s END /main/devicestate/ - devstate_prov_del Time: <1ms Result: PASS 304s START /main/devicestate/ - devstate_prov_add 304s END /main/devicestate/ - devstate_prov_add Time: <1ms Result: PASS 304s START /main/devicestate/ - device2extenstate_test 304s END /main/devicestate/ - device2extenstate_test Time: <1ms Result: PASS 304s START /main/devicestate/ - device_state_aggregation_test 304s END /main/devicestate/ - device_state_aggregation_test Time: <1ms Result: PASS 304s START /main/dns/ - resolver_resolve_async_cancel 304s END /main/dns/ - resolver_resolve_async_cancel Time: <1ms Result: PASS 304s START /main/dns/ - resolver_resolve_async_off_nominal 304s END /main/dns/ - resolver_resolve_async_off_nominal Time: <1ms Result: PASS 304s START /main/dns/ - resolver_resolve_async 309s END /main/dns/ - resolver_resolve_async Time: 5000ms Result: PASS 309s START /main/dns/ - resolver_resolve_sync_off_nominal 309s END /main/dns/ - resolver_resolve_sync_off_nominal Time: <1ms Result: PASS 309s START /main/dns/ - resolver_resolve_sync 314s END /main/dns/ - resolver_resolve_sync Time: 5000ms Result: PASS 314s START /main/dns/ - resolver_add_record_off_nominal 314s END /main/dns/ - resolver_add_record_off_nominal Time: <1ms Result: PASS 314s START /main/dns/ - resolver_add_record 314s END /main/dns/ - resolver_add_record Time: <1ms Result: PASS 314s START /main/dns/ - resolver_set_result_off_nominal 314s END /main/dns/ - resolver_set_result_off_nominal Time: <1ms Result: PASS 314s START /main/dns/ - resolver_set_result 314s END /main/dns/ - resolver_set_result Time: <1ms Result: PASS 314s START /main/dns/ - resolver_data 314s END /main/dns/ - resolver_data Time: <1ms Result: PASS 314s START /main/dns/ - resolver_unregister_off_nominal 314s END /main/dns/ - resolver_unregister_off_nominal Time: <1ms Result: PASS 314s START /main/dns/ - resolver_register_off_nominal 314s END /main/dns/ - resolver_register_off_nominal Time: <1ms Result: PASS 314s START /main/dns/ - resolver_register_unregister 314s END /main/dns/ - resolver_register_unregister Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve_off_nominal_interactions 314s END /main/dns/naptr/ - naptr_resolve_off_nominal_interactions Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve_off_nominal_regexp 314s END /main/dns/naptr/ - naptr_resolve_off_nominal_regexp Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve_off_nominal_services 314s END /main/dns/naptr/ - naptr_resolve_off_nominal_services Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve_off_nominal_flags 314s END /main/dns/naptr/ - naptr_resolve_off_nominal_flags Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve_off_nominal_length 314s END /main/dns/naptr/ - naptr_resolve_off_nominal_length Time: <1ms Result: PASS 314s START /main/dns/naptr/ - naptr_resolve 314s END /main/dns/naptr/ - naptr_resolve Time: <1ms Result: PASS 314s START /main/dns/query_set/ - query_set_off_nominal_cancel 314s END /main/dns/query_set/ - query_set_off_nominal_cancel Time: <1ms Result: PASS 314s START /main/dns/query_set/ - query_set_nominal_cancel 314s END /main/dns/query_set/ - query_set_nominal_cancel Time: <1ms Result: PASS 314s START /main/dns/query_set/ - query_set_empty 314s END /main/dns/query_set/ - query_set_empty Time: <1ms Result: PASS 314s START /main/dns/query_set/ - query_set 314s END /main/dns/query_set/ - query_set Time: <1ms Result: PASS 314s START /main/dns/recurring/ - recurring_query_cancel_during 314s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 321s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 331s END /main/dns/recurring/ - recurring_query_cancel_during Time: 17000ms Result: PASS 331s START /main/dns/recurring/ - recurring_query_cancel_between 331s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 341s END /main/dns/recurring/ - recurring_query_cancel_between Time: 10000ms Result: PASS 341s START /main/dns/recurring/ - recurring_query_off_nominal 341s END /main/dns/recurring/ - recurring_query_off_nominal Time: <1ms Result: PASS 341s START /main/dns/recurring/ - recurring_query 341s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 348s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 360s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 360s END /main/dns/recurring/ - recurring_query Time: 18999ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_record_missing_host 360s END /main/dns/srv/ - srv_resolve_record_missing_host Time: <1ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_record_missing_port_host 360s END /main/dns/srv/ - srv_resolve_record_missing_port_host Time: <1ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_record_missing_weight_port_host 360s END /main/dns/srv/ - srv_resolve_record_missing_weight_port_host Time: <1ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_different_priorities_different_weights 360s END /main/dns/srv/ - srv_resolve_different_priorities_different_weights Time: 10ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_same_priority_different_weights 360s END /main/dns/srv/ - srv_resolve_same_priority_different_weights Time: 8ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_same_priority_zero_weight 360s END /main/dns/srv/ - srv_resolve_same_priority_zero_weight Time: <1ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_sort_priority 360s END /main/dns/srv/ - srv_resolve_sort_priority Time: <1ms Result: PASS 360s START /main/dns/srv/ - srv_resolve_single_record 360s END /main/dns/srv/ - srv_resolve_single_record Time: <1ms Result: PASS 360s START /main/dsp/ - dtmf 360s END /main/dsp/ - dtmf Time: 4ms Result: PASS 360s START /main/dsp/ - fax 361s END /main/dsp/ - fax Time: 728ms Result: PASS 361s START /main/event/ - ast_event_new_test 361s [test_event.c:event_new_test:125]: First, test dynamic event creation... 361s [test_event.c:check_event:88]: Event looks good. 361s [test_event.c:check_event:88]: Event looks good. 361s END /main/event/ - ast_event_new_test Time: <1ms Result: PASS 361s START /main/file/ - read_dir_test 361s END /main/file/ - read_dir_test Time: <1ms Result: PASS 361s START /main/file/ - ast_format_str_reduce_test_1 361s END /main/file/ - ast_format_str_reduce_test_1 Time: <1ms Result: PASS 361s START /main/format_cache/ - format_cache_get_nonxistent 361s END /main/format_cache/ - format_cache_get_nonxistent Time: <1ms Result: PASS 361s START /main/format_cache/ - format_cache_get 361s END /main/format_cache/ - format_cache_get Time: <1ms Result: PASS 361s START /main/format_cache/ - format_cache_set_null 361s END /main/format_cache/ - format_cache_set_null Time: <1ms Result: PASS 361s START /main/format_cache/ - format_cache_set_duplicate 361s END /main/format_cache/ - format_cache_set_duplicate Time: <1ms Result: PASS 361s START /main/format_cache/ - format_cache_set 361s END /main/format_cache/ - format_cache_set Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_replace_from_cap 361s END /main/format_cap/ - format_cap_replace_from_cap Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_best_by_type 361s END /main/format_cap/ - format_cap_best_by_type Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_iscompatible 361s END /main/format_cap/ - format_cap_iscompatible Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_get_compatible 361s END /main/format_cap/ - format_cap_get_compatible Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_iscompatible_format 361s END /main/format_cap/ - format_cap_iscompatible_format Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_get_compatible_format 361s END /main/format_cap/ - format_cap_get_compatible_format Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_get_names 361s END /main/format_cap/ - format_cap_get_names Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_remove_all 361s END /main/format_cap/ - format_cap_remove_all Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_remove_bytype 361s END /main/format_cap/ - format_cap_remove_bytype Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_remove_multiple 361s END /main/format_cap/ - format_cap_remove_multiple Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_remove_single 361s END /main/format_cap/ - format_cap_remove_single Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_set_framing 361s END /main/format_cap/ - format_cap_set_framing Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_from_cap_duplicate 361s END /main/format_cap/ - format_cap_append_from_cap_duplicate Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_from_cap 361s END /main/format_cap/ - format_cap_append_from_cap Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_duplicate 361s END /main/format_cap/ - format_cap_append_duplicate Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_all_audio 361s END /main/format_cap/ - format_cap_append_all_audio Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_all_unknown 361s END /main/format_cap/ - format_cap_append_all_unknown Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_multiple 361s END /main/format_cap/ - format_cap_append_multiple Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_append_single 361s END /main/format_cap/ - format_cap_append_single Time: <1ms Result: PASS 361s START /main/format_cap/ - format_cap_alloc 361s END /main/format_cap/ - format_cap_alloc Time: <1ms Result: PASS 361s START /main/hashtab/ - thrash 361s [test_hashtab_thrash.c:hash_test:246]: Executing hash concurrency test... 361s END /main/hashtab/ - thrash Time: 577ms Result: PASS 361s START /main/heap/ - heap_test_3 361s END /main/heap/ - heap_test_3 Time: 94ms Result: PASS 361s START /main/heap/ - heap_test_2 361s END /main/heap/ - heap_test_2 Time: 87ms Result: PASS 361s START /main/heap/ - heap_test_1 361s END /main/heap/ - heap_test_1 Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_resynch_control 361s END /main/jitterbuf/ - jitterbuffer_resynch_control Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_resynch_voice 361s END /main/jitterbuf/ - jitterbuffer_resynch_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_overflow_control 361s END /main/jitterbuf/ - jitterbuffer_overflow_control Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_overflow_voice 361s END /main/jitterbuf/ - jitterbuffer_overflow_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_late_control 361s END /main/jitterbuf/ - jitterbuffer_late_control Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_late_voice 361s END /main/jitterbuf/ - jitterbuffer_late_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_lost_control 361s END /main/jitterbuf/ - jitterbuffer_lost_control Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_lost_voice 361s END /main/jitterbuf/ - jitterbuffer_lost_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 361s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 361s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_nominal_control_frames 361s END /main/jitterbuf/ - jitterbuffer_nominal_control_frames Time: <1ms Result: PASS 361s START /main/jitterbuf/ - jitterbuffer_nominal_voice_frames 361s END /main/jitterbuf/ - jitterbuffer_nominal_voice_frames Time: <1ms Result: PASS 361s START /main/json/ - cep 361s END /main/json/ - cep Time: <1ms Result: PASS 361s START /main/json/ - type_timeval 361s END /main/json/ - type_timeval Time: <1ms Result: PASS 361s START /main/json/ - name_number 361s END /main/json/ - name_number Time: <1ms Result: PASS 361s START /main/json/ - clever_circle 361s END /main/json/ - clever_circle Time: <1ms Result: PASS 361s START /main/json/ - circular_array 361s END /main/json/ - circular_array Time: <1ms Result: PASS 361s START /main/json/ - circular_object 361s END /main/json/ - circular_object Time: <1ms Result: PASS 361s START /main/json/ - copy_null 361s END /main/json/ - copy_null Time: <1ms Result: PASS 361s START /main/json/ - deep_copy 361s END /main/json/ - deep_copy Time: <1ms Result: PASS 361s START /main/json/ - copy 361s END /main/json/ - copy Time: <1ms Result: PASS 361s START /main/json/ - object_alloc 361s END /main/json/ - object_alloc Time: <1ms Result: PASS 361s START /main/json/ - pack_ownership 361s END /main/json/ - pack_ownership Time: <1ms Result: PASS 361s START /main/json/ - pack 361s END /main/json/ - pack Time: <1ms Result: PASS 361s START /main/json/ - parse_errors 361s END /main/json/ - parse_errors Time: <1ms Result: PASS 361s START /main/json/ - dump_load_null 361s END /main/json/ - dump_load_null Time: <1ms Result: PASS 361s START /main/json/ - dump_load_new_file 361s END /main/json/ - dump_load_new_file Time: <1ms Result: PASS 361s START /main/json/ - dump_load_file 361s END /main/json/ - dump_load_file Time: <1ms Result: PASS 361s START /main/json/ - load_buffer 361s END /main/json/ - load_buffer Time: <1ms Result: PASS 361s START /main/json/ - dump_str_fail 361s END /main/json/ - dump_str_fail Time: <1ms Result: PASS 361s START /main/json/ - dump_load_str 361s END /main/json/ - dump_load_str Time: <1ms Result: PASS 361s START /main/json/ - dump_load_string 361s END /main/json/ - dump_load_string Time: <1ms Result: PASS 361s START /main/json/ - object_create_vars 361s END /main/json/ - object_create_vars Time: <1ms Result: PASS 361s START /main/json/ - object_iter_null 361s END /main/json/ - object_iter_null Time: <1ms Result: PASS 361s START /main/json/ - object_iter 361s END /main/json/ - object_iter Time: <1ms Result: PASS 361s START /main/json/ - object_null 361s END /main/json/ - object_null Time: <1ms Result: PASS 361s START /main/json/ - object_merge_missing 361s END /main/json/ - object_merge_missing Time: <1ms Result: PASS 361s START /main/json/ - object_alloc 361s END /main/json/ - object_alloc Time: <1ms Result: PASS 361s START /main/json/ - object_alloc 361s END /main/json/ - object_alloc Time: <1ms Result: PASS 361s START /main/json/ - object_clear 361s END /main/json/ - object_clear Time: <1ms Result: PASS 361s START /main/json/ - object_del 361s END /main/json/ - object_del Time: <1ms Result: PASS 361s START /main/json/ - object_get 361s END /main/json/ - object_get Time: <1ms Result: PASS 361s START /main/json/ - object_set_overwriting 361s END /main/json/ - object_set_overwriting Time: <1ms Result: PASS 361s START /main/json/ - object_set 361s END /main/json/ - object_set Time: <1ms Result: PASS 361s START /main/json/ - object_alloc 361s END /main/json/ - object_alloc Time: <1ms Result: PASS 361s START /main/json/ - array_null 361s END /main/json/ - array_null Time: <1ms Result: PASS 361s START /main/json/ - array_extend 361s END /main/json/ - array_extend Time: <1ms Result: PASS 361s START /main/json/ - array_clear 361s END /main/json/ - array_clear Time: <1ms Result: PASS 361s START /main/json/ - array_remove 361s END /main/json/ - array_remove Time: <1ms Result: PASS 361s START /main/json/ - array_set 361s END /main/json/ - array_set Time: <1ms Result: PASS 361s START /main/json/ - array_insert 361s END /main/json/ - array_insert Time: <1ms Result: PASS 361s START /main/json/ - array_append 361s END /main/json/ - array_append Time: <1ms Result: PASS 361s START /main/json/ - array_create 361s END /main/json/ - array_create Time: <1ms Result: PASS 361s START /main/json/ - non_int 361s END /main/json/ - non_int Time: <1ms Result: PASS 361s START /main/json/ - type_int 361s END /main/json/ - type_int Time: <1ms Result: PASS 361s START /main/json/ - stringf 361s END /main/json/ - stringf Time: <1ms Result: PASS 361s START /main/json/ - string_null 361s END /main/json/ - string_null Time: <1ms Result: PASS 361s START /main/json/ - type_string 361s END /main/json/ - type_string Time: <1ms Result: PASS 361s START /main/json/ - null_val 361s END /main/json/ - null_val Time: <1ms Result: PASS 361s START /main/json/ - type_null 361s END /main/json/ - type_null Time: <1ms Result: PASS 361s START /main/json/ - type_bool1 361s END /main/json/ - type_bool1 Time: <1ms Result: PASS 361s START /main/json/ - type_bool0 361s END /main/json/ - type_bool0 Time: <1ms Result: PASS 361s START /main/json/ - type_true 361s END /main/json/ - type_true Time: <1ms Result: PASS 361s START /main/json/ - type_false 361s END /main/json/ - type_false Time: <1ms Result: PASS 361s START /main/linkedlists/ - double_ll_tests 361s END /main/linkedlists/ - double_ll_tests Time: <1ms Result: PASS 361s START /main/linkedlists/ - ll_tests 361s END /main/linkedlists/ - ll_tests Time: <1ms Result: PASS 361s START /main/lock/ - cleanup_order_test 361s [test_scoped_lock.c:test_ref:149]: Ref is occurring 361s [test_scoped_lock.c:test_lock:117]: Lock is occurring 361s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 361s [test_scoped_lock.c:test_unref:166]: Unref is occurring 361s [test_scoped_lock.c:test_ref:149]: Ref is occurring 361s [test_scoped_lock.c:test_lock:117]: Lock is occurring 361s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 361s [test_scoped_lock.c:test_unref:166]: Unref is occurring 361s END /main/lock/ - cleanup_order_test Time: <1ms Result: PASS 361s START /main/lock/ - lock_test 361s END /main/lock/ - lock_test Time: <1ms Result: PASS 361s START /main/lock/ - named_lock_test 361s [test_named_lock.c:named_lock_test:80]: This test should take about 3 seconds 364s END /main/lock/ - named_lock_test Time: 3000ms Result: PASS 364s START /main/logging/ - scope_test 364s END /main/logging/ - scope_test Time: <1ms Result: PASS 364s START /main/manager/ - originate_permissions_test 364s END /main/manager/ - originate_permissions_test Time: <1ms Result: PASS 364s START /main/manager/ - eventfilter_test_matching 364s Loaded 7 filters 364s Tested 9 events 364s END /main/manager/ - eventfilter_test_matching Time: <1ms Result: PASS 364s START /main/manager/ - eventfilter_test_creation 364s [manager.c:eventfilter_test_creation:6215]: Tested 29 filters 364s END /main/manager/ - eventfilter_test_creation Time: <1ms Result: PASS 364s START /main/media_cache/ - create_update_off_nominal 364s END /main/media_cache/ - create_update_off_nominal Time: <1ms Result: PASS 364s START /main/media_cache/ - create_update_metadata 364s [test_media_cache.c:create_update_metadata:367]: Got /tmp/test-media-cache-dye0Q3 for second file path 364s END /main/media_cache/ - create_update_metadata Time: <1ms Result: PASS 364s START /main/media_cache/ - create_update_nominal 364s [test_media_cache.c:create_update_nominal:236]: Creating resource with /tmp/test-media-cache-JkhDRY 364s [test_media_cache.c:create_update_nominal:241]: Got /tmp/test-media-cache-JkhDRY for first file path 364s [test_media_cache.c:create_update_nominal:245]: Creating resource with /tmp/test-media-cache-nh1841 364s [test_media_cache.c:create_update_nominal:250]: Got /tmp/test-media-cache-nh1841 for second file path 364s END /main/media_cache/ - create_update_nominal Time: 11ms Result: PASS 364s START /main/media_cache/ - exists_off_nominal 364s END /main/media_cache/ - exists_off_nominal Time: <1ms Result: PASS 364s START /main/media_cache/ - exists_nominal 364s END /main/media_cache/ - exists_nominal Time: <1ms Result: PASS 364s START /main/netsock2/ - split_hostport 364s END /main/netsock2/ - split_hostport Time: <1ms Result: PASS 364s START /main/netsock2/ - parsing 364s END /main/netsock2/ - parsing Time: <1ms Result: PASS 364s START /main/optional_api/ - test_provide_last 364s END /main/optional_api/ - test_provide_last Time: <1ms Result: PASS 364s START /main/optional_api/ - test_provide_first 364s END /main/optional_api/ - test_provide_first Time: <1ms Result: PASS 364s START /main/pbx/ - test_substitution 364s [test_substitution.c:test_substitution:244]: Testing variable substitution ... 364s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGANI2}' . . . . . passed 364s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTON}' . . . . . passed 364s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTNS}' . . . . . passed 364s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${HANGUPCAUSE}' . . . . . passed 364s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${PRIORITY}' . . . . . passed 364s [test_substitution.c:test_chan_string:115]: Tested '${CONTEXT}' . . . . . passed 364s [test_substitution.c:test_chan_string:115]: Tested '${EXTEN}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(language)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(musicclass)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(parkinglot)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CALLERID(name)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CURLOPT(proxyuserpwd)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${CDR(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${ENV(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${GLOBAL(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_variable:144]: Tested '${GROUP()}' . . . . . passed 364s [test_substitution.c:test_2way_function:193]: Tested '${AES_ENCRYPT(abcdefghijklmnop,)}' and '${AES_DECRYPT(abcdefghijklmnop,)}' . . . . . passed 364s [test_substitution.c:test_2way_function:193]: Tested '${BASE64_ENCODE()}' and '${BASE64_DECODE()}' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '123123' ('${foo}${foo}') == '123123' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A123A123A' ('A${foo}A${foo}A') == 'A123A123A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${bar}}A') == 'A123A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${baz}o}A') == 'A123A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A23A' ('A${${baz}o:1}A') == 'A23A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:1}A') == 'A2A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:-1}A') == 'A2A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A3A' ('A${${baz}o:-1:1}A') == 'A3A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:1}A') == 'A2A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:-1}A') == 'A2A' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'cd&ef' ('${LISTFILTER(list1,&,ab)}') == 'cd&ef' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'ab&ef' ('${LISTFILTER(list1,&,cd)}') == 'ab&ef' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd' ('${LISTFILTER(list1,&,ef)}') == 'ab&cd' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,gh)}') == 'ab&cd&ef' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,c)}') == 'ab&cd&ef' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,d)}') == 'ab&cd&ef' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list2,&,ab)}') == '' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list_empty,&,ab)}') == '' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '123,456' ('${SHELL(printf '%d' 123)},${SHELL(printf '%d' 456)}') == '123,456' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '123,,456' ('${foo},${CDR(answer)},${SHELL(printf '%d' 456)}') == '123,,456' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '123,0.000000,456' ('${foo},${CDR(answer,u)},${SHELL(printf '%d' 456)}') == '123,0.000000,456' . . . . . passed 364s [test_substitution.c:test_expected_result:215]: Tested '123,,' ('${foo},${this_does_not_exist},${THIS_DOES_NOT_EXIST(either)}') == '123,,' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${BLACKLIST(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${EVAL(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${FIELDNUM(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${FIELDQTY(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${HASHKEYS(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${IMPORT(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${PP_EACH_USER(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${TOLOWER(foo)}' . . . . . passed 364s [test_substitution.c:test_chan_function:168]: Tested '${TOUPPER(foo)}' . . . . . passed 364s END /main/pbx/ - test_substitution Time: 17ms Result: PASS 364s START /main/pbx/ - pattern_match_test 364s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the old pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the old pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the new pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 364s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the new pattern match engine 364s END /main/pbx/ - pattern_match_test Time: <1ms Result: PASS 364s START /main/pbx/ - test_MATH_function 364s [func_math.c:test_MATH_function:682]: Testing MATH() substitution ... 364s END /main/pbx/ - test_MATH_function Time: <1ms Result: PASS 364s START /main/pbx/ - variable_substrings 364s END /main/pbx/ - variable_substrings Time: <1ms Result: PASS 364s START /main/poll/ - poll_test 364s [test_poll.c:poll_test:95]: Creating handle that should NEVER block on write 364s [test_poll.c:poll_test:101]: Creating handle that should NEVER block on read 364s [test_poll.c:poll_test:108]: Creating handle that should block on read 364s [test_poll.c:poll_test:168]: Starting thread to ensure we don't block forever 364s [test_poll.c:poll_test:194]: Cancelling failsafe thread. 364s END /main/poll/ - poll_test Time: <1ms Result: PASS 364s START /main/presence/ - channel_presence 364s END /main/presence/ - channel_presence Time: <1ms Result: PASS 364s START /main/sample/ - sample_test 364s [test_skel.c:sample_test:93]: Test argument: 0: test 364s [test_skel.c:sample_test:93]: Test argument: 1: execute 364s [test_skel.c:sample_test:93]: Test argument: 2: all 364s [test_skel.c:sample_test:102]: Executing sample test with test-option=999 and test-option2= 364s END /main/sample/ - sample_test Time: <1ms Result: PASS 364s START /main/sched/ - sched_test_freebird 364s [test_sched.c:sched_test_freebird:440]: Received signal, calling Scedule and UNREF 364s [test_sched.c:sched_test_freebird:441]: ID: 1 367s [test_sched.c:sched_test_freebird:448]: Correct number of references '2' 367s END /main/sched/ - sched_test_freebird Time: 3000ms Result: PASS 367s START /main/sched/ - sched_test_order 368s END /main/sched/ - sched_test_order Time: 400ms Result: PASS 368s START /main/sorcery/ - wizard_read_only 368s END /main/sorcery/ - wizard_read_only Time: <1ms Result: PASS 368s START /main/sorcery/ - wizard_observation 368s END /main/sorcery/ - wizard_observation Time: <1ms Result: PASS 368s START /main/sorcery/ - instance_observation 368s END /main/sorcery/ - instance_observation Time: <1ms Result: PASS 368s START /main/sorcery/ - global_observation 368s END /main/sorcery/ - global_observation Time: <1ms Result: PASS 368s START /main/sorcery/ - object_field_registered 368s END /main/sorcery/ - object_field_registered Time: <1ms Result: PASS 368s START /main/sorcery/ - dialplan_function 368s END /main/sorcery/ - dialplan_function Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all 368s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple 368s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard_retrieve_field 368s END /main/sorcery/ - configuration_file_wizard_retrieve_field Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard_with_criteria 368s END /main/sorcery/ - configuration_file_wizard_with_criteria Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard_with_file_integrity 368s END /main/sorcery/ - configuration_file_wizard_with_file_integrity Time: <1ms Result: PASS 368s START /main/sorcery/ - configuration_file_wizard 368s END /main/sorcery/ - configuration_file_wizard Time: <1ms Result: PASS 368s START /main/sorcery/ - object_type_observer 368s END /main/sorcery/ - object_type_observer Time: <1ms Result: PASS 368s START /main/sorcery/ - caching_wizard_behavior 368s END /main/sorcery/ - caching_wizard_behavior Time: <1ms Result: PASS 368s START /main/sorcery/ - object_is_stale 368s END /main/sorcery/ - object_is_stale Time: <1ms Result: PASS 368s START /main/sorcery/ - object_delete_uncreated 368s END /main/sorcery/ - object_delete_uncreated Time: <1ms Result: PASS 368s START /main/sorcery/ - object_delete 368s END /main/sorcery/ - object_delete Time: <1ms Result: PASS 368s START /main/sorcery/ - object_update_uncreated 368s END /main/sorcery/ - object_update_uncreated Time: <1ms Result: PASS 368s START /main/sorcery/ - object_update 368s END /main/sorcery/ - object_update Time: <1ms Result: PASS 368s START /main/sorcery/ - object_retrieve_regex 368s END /main/sorcery/ - object_retrieve_regex Time: <1ms Result: PASS 368s START /main/sorcery/ - object_retrieve_multiple_field 368s END /main/sorcery/ - object_retrieve_multiple_field Time: <1ms Result: PASS 368s START /main/sorcery/ - object_retrieve_multiple_all 368s END /main/sorcery/ - object_retrieve_multiple_all Time: <1ms Result: PASS 368s START /main/sorcery/ - object_retrieve_field 368s END /main/sorcery/ - object_retrieve_field Time: <1ms Result: PASS 368s START /main/sorcery/ - object_retrieve_id 368s END /main/sorcery/ - object_retrieve_id Time: <1ms Result: PASS 368s START /main/sorcery/ - object_create 368s END /main/sorcery/ - object_create Time: <1ms Result: PASS 368s START /main/sorcery/ - changeset_create_unchanged 368s END /main/sorcery/ - changeset_create_unchanged Time: <1ms Result: PASS 368s START /main/sorcery/ - changeset_create 368s END /main/sorcery/ - changeset_create Time: <1ms Result: PASS 368s START /main/sorcery/ - extended_fields 368s END /main/sorcery/ - extended_fields Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_apply_fields 368s END /main/sorcery/ - objectset_apply_fields Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_transform 368s END /main/sorcery/ - objectset_transform Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_apply_invalid 368s END /main/sorcery/ - objectset_apply_invalid Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_apply_handler 368s END /main/sorcery/ - objectset_apply_handler Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_apply 368s END /main/sorcery/ - objectset_apply Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_create_regex 368s END /main/sorcery/ - objectset_create_regex Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_json_create 368s END /main/sorcery/ - objectset_json_create Time: <1ms Result: PASS 368s START /main/sorcery/ - objectset_create 368s END /main/sorcery/ - objectset_create Time: <1ms Result: PASS 368s START /main/sorcery/ - object_diff_native 368s END /main/sorcery/ - object_diff_native Time: <1ms Result: PASS 368s START /main/sorcery/ - object_diff 368s END /main/sorcery/ - object_diff Time: <1ms Result: PASS 368s START /main/sorcery/ - object_copy_native 368s END /main/sorcery/ - object_copy_native Time: <1ms Result: PASS 368s START /main/sorcery/ - object_copy 368s END /main/sorcery/ - object_copy Time: <1ms Result: PASS 368s START /main/sorcery/ - object_alloc_without_id 368s END /main/sorcery/ - object_alloc_without_id Time: <1ms Result: PASS 368s START /main/sorcery/ - object_alloc_with_id 368s END /main/sorcery/ - object_alloc_with_id Time: <1ms Result: PASS 368s START /main/sorcery/ - object_fields_register 368s END /main/sorcery/ - object_fields_register Time: <1ms Result: PASS 368s START /main/sorcery/ - object_field_register 368s END /main/sorcery/ - object_field_register Time: <1ms Result: PASS 368s START /main/sorcery/ - object_register_without_mapping 368s END /main/sorcery/ - object_register_without_mapping Time: <1ms Result: PASS 368s START /main/sorcery/ - object_register 368s END /main/sorcery/ - object_register Time: <1ms Result: PASS 368s START /main/sorcery/ - apply_config 368s END /main/sorcery/ - apply_config Time: <1ms Result: PASS 368s START /main/sorcery/ - apply_default 368s END /main/sorcery/ - apply_default Time: <1ms Result: PASS 368s START /main/sorcery/ - open 368s END /main/sorcery/ - open Time: <1ms Result: PASS 368s START /main/sorcery/ - wizard_registration 368s END /main/sorcery/ - wizard_registration Time: <1ms Result: PASS 368s START /main/sorcery/ - wizard_apply_and_insert 368s END /main/sorcery/ - wizard_apply_and_insert Time: <1ms Result: PASS 368s START /main/stdtime/ - time_create_by_unit_str 368s END /main/stdtime/ - time_create_by_unit_str Time: <1ms Result: PASS 368s START /main/stdtime/ - time_create_by_unit 368s END /main/stdtime/ - time_create_by_unit Time: <1ms Result: PASS 368s START /main/stdtime/ - time_str_to_unit 368s END /main/stdtime/ - time_str_to_unit Time: <1ms Result: PASS 368s START /main/stdtime/ - time_tv_to_usec 368s END /main/stdtime/ - time_tv_to_usec Time: <1ms Result: PASS 368s START /main/stdtime/ - timezone_watch 368s [test_time.c:test_timezone_watch:82]: Executing deletion test... 368s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.XZB9HB/test 369s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.XZB9HB/test 369s [test_time.c:test_timezone_watch:82]: Executing symlink test... 369s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.XZB9HB/test 370s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.XZB9HB/test 370s END /main/stdtime/ - timezone_watch Time: 2293ms Result: PASS 370s START /main/stream/ - stream_topology_map_create 370s END /main/stream/ - stream_topology_map_create Time: <1ms Result: PASS 370s START /main/stream/ - format_cap_from_stream_topology 370s END /main/stream/ - format_cap_from_stream_topology Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_change_request_from_channel 370s END /main/stream/ - stream_topology_change_request_from_channel Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_change_request_from_application 370s END /main/stream/ - stream_topology_change_request_from_application Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_change_request_from_channel_non_multistream 370s END /main/stream/ - stream_topology_change_request_from_channel_non_multistream Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_change_request_from_application_non_multistream 370s END /main/stream/ - stream_topology_change_request_from_application_non_multistream Time: <1ms Result: PASS 370s START /main/stream/ - stream_read_multistream 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 8 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 8 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 370s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s END /main/stream/ - stream_read_multistream Time: 1ms Result: PASS 370s START /main/stream/ - stream_read_non_multistream 370s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 370s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 370s END /main/stream/ - stream_read_non_multistream Time: <1ms Result: PASS 370s START /main/stream/ - stream_write_multistream 370s END /main/stream/ - stream_write_multistream Time: <1ms Result: PASS 370s START /main/stream/ - stream_write_non_multistream 370s END /main/stream/ - stream_write_non_multistream Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_channel_set 370s END /main/stream/ - stream_topology_channel_set Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_create_from_channel_nativeformats 370s END /main/stream/ - stream_topology_create_from_channel_nativeformats Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_get_first_stream_by_type 370s END /main/stream/ - stream_topology_get_first_stream_by_type Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_create_from_format_cap 370s END /main/stream/ - stream_topology_create_from_format_cap Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_del_stream 370s END /main/stream/ - stream_topology_del_stream Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_set_stream 370s END /main/stream/ - stream_topology_set_stream Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_append_stream 370s END /main/stream/ - stream_topology_append_stream Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_clone 370s END /main/stream/ - stream_topology_clone Time: <1ms Result: PASS 370s START /main/stream/ - stream_topology_create 370s END /main/stream/ - stream_topology_create Time: <1ms Result: PASS 370s START /main/stream/ - stream_metadata 370s END /main/stream/ - stream_metadata Time: <1ms Result: PASS 370s START /main/stream/ - stream_set_state 370s END /main/stream/ - stream_set_state Time: <1ms Result: PASS 370s START /main/stream/ - stream_set_formats 370s END /main/stream/ - stream_set_formats Time: <1ms Result: PASS 370s START /main/stream/ - stream_set_type 370s END /main/stream/ - stream_set_type Time: <1ms Result: PASS 370s START /main/stream/ - stream_create_no_name 370s END /main/stream/ - stream_create_no_name Time: <1ms Result: PASS 370s START /main/stream/ - stream_create 370s END /main/stream/ - stream_create Time: <1ms Result: PASS 370s START /main/strings/ - in_delimited_string 370s END /main/strings/ - in_delimited_string Time: <1ms Result: PASS 370s START /main/strings/ - temp_strings 370s END /main/strings/ - temp_strings Time: <1ms Result: PASS 370s START /main/strings/ - strings_match 370s END /main/strings/ - strings_match Time: <1ms Result: PASS 370s START /main/strings/ - escape 370s END /main/strings/ - escape Time: <1ms Result: PASS 370s START /main/strings/ - escape_semicolons 370s END /main/strings/ - escape_semicolons Time: <1ms Result: PASS 370s START /main/strings/ - strsep_quoted 370s END /main/strings/ - strsep_quoted Time: <1ms Result: PASS 370s START /main/strings/ - strsep 370s END /main/strings/ - strsep Time: <1ms Result: PASS 370s START /main/strings/ - ends_with 370s END /main/strings/ - ends_with Time: <1ms Result: PASS 370s START /main/strings/ - begins_with 370s END /main/strings/ - begins_with Time: <1ms Result: PASS 370s START /main/strings/ - str_test 370s END /main/strings/ - str_test Time: <1ms Result: PASS 370s START /main/taskprocessor/ - serializer_pool 374s END /main/taskprocessor/ - serializer_pool Time: 4000ms Result: PASS 374s START /main/taskprocessor/ - taskprocessor_push_local 374s END /main/taskprocessor/ - taskprocessor_push_local Time: <1ms Result: PASS 374s START /main/taskprocessor/ - taskprocessor_shutdown 374s END /main/taskprocessor/ - taskprocessor_shutdown Time: <1ms Result: PASS 374s START /main/taskprocessor/ - taskprocessor_listener 374s END /main/taskprocessor/ - taskprocessor_listener Time: <1ms Result: PASS 374s START /main/taskprocessor/ - subsystem_alert 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 1 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 2 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 3 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 4 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 5 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 6 374s [test_taskprocessor.c:subsystem_alert:237]: Subsystem alert triggered correctly at 6 374s [test_taskprocessor.c:subsystem_alert:240]: Global alert triggered correctly at 6 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 7 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 8 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 9 374s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 10 374s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 1 375s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 2 375s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 3 376s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 4 376s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 5 377s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 6 377s [test_taskprocessor.c:subsystem_alert:279]: Subsystem alert cleared correctly at 3 377s [test_taskprocessor.c:subsystem_alert:282]: Global alert cleared correctly at 3 377s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 7 378s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 8 378s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 9 379s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 10 379s END /main/taskprocessor/ - subsystem_alert Time: 5003ms Result: PASS 379s START /main/taskprocessor/ - default_taskprocessor_load 379s END /main/taskprocessor/ - default_taskprocessor_load Time: 43ms Result: PASS 379s START /main/taskprocessor/ - default_taskprocessor 379s END /main/taskprocessor/ - default_taskprocessor Time: <1ms Result: PASS 379s START /main/test/ - registrations 379s END /main/test/ - registrations Time: <1ms Result: PASS 379s START /main/test_capture/ - test_capture_false 379s [test_capture.c:test_capture_false:120]: Executing false exit test... 379s END /main/test_capture/ - test_capture_false Time: 16ms Result: PASS 379s START /main/test_capture/ - test_capture_true 379s [test_capture.c:test_capture_true:61]: Executing true exit test... 379s END /main/test_capture/ - test_capture_true Time: 14ms Result: PASS 379s START /main/test_capture/ - test_capture_stdout_stderr 379s [test_capture.c:test_capture_stdout_stderr:318]: Executing stdout/stderr test... 379s END /main/test_capture/ - test_capture_stdout_stderr Time: 14ms Result: PASS 379s START /main/test_capture/ - test_capture_with_dynamic 379s [test_capture.c:test_capture_with_dynamic:249]: Executing dynamic argument test... 379s [test_capture.c:test_capture_with_dynamic:272]: unexpected value for stdout 379s END /main/test_capture/ - test_capture_with_dynamic Time: 14ms Result: FAIL 379s START /main/test_capture/ - test_capture_with_stdin 379s [test_capture.c:test_capture_with_stdin:183]: Executing stdin test... 379s END /main/test_capture/ - test_capture_with_stdin Time: 16ms Result: PASS 379s START /main/threadpool/ - threadpool_serializer_dupe 379s END /main/threadpool/ - threadpool_serializer_dupe Time: <1ms Result: PASS 379s START /main/threadpool/ - threadpool_serializer 380s END /main/threadpool/ - threadpool_serializer Time: 1001ms Result: PASS 380s START /main/threadpool/ - more_destruction 380s END /main/threadpool/ - more_destruction Time: 1ms Result: PASS 380s START /main/threadpool/ - task_distribution 380s END /main/threadpool/ - task_distribution Time: <1ms Result: PASS 380s START /main/threadpool/ - reactivation 380s END /main/threadpool/ - reactivation Time: <1ms Result: PASS 380s START /main/threadpool/ - max_size 380s END /main/threadpool/ - max_size Time: <1ms Result: PASS 380s START /main/threadpool/ - auto_increment 380s END /main/threadpool/ - auto_increment Time: <1ms Result: PASS 380s START /main/threadpool/ - one_thread_multiple_tasks 380s END /main/threadpool/ - one_thread_multiple_tasks Time: <1ms Result: PASS 380s START /main/threadpool/ - one_thread_one_task 380s END /main/threadpool/ - one_thread_one_task Time: <1ms Result: PASS 380s START /main/threadpool/ - one_task_one_thread 380s END /main/threadpool/ - one_task_one_thread Time: <1ms Result: PASS 380s START /main/threadpool/ - thread_timeout_thrash 411s END /main/threadpool/ - thread_timeout_thrash Time: 31018ms Result: PASS 411s START /main/threadpool/ - thread_timeout 413s END /main/threadpool/ - thread_timeout Time: 2000ms Result: PASS 413s START /main/threadpool/ - thread_destruction 413s END /main/threadpool/ - thread_destruction Time: 1ms Result: PASS 413s START /main/threadpool/ - thread_creation 413s END /main/threadpool/ - thread_creation Time: <1ms Result: PASS 413s START /main/threadpool/ - initial_threads 413s END /main/threadpool/ - initial_threads Time: <1ms Result: PASS 413s START /main/threadpool/ - push 413s END /main/threadpool/ - push Time: <1ms Result: PASS 413s START /main/uri/ - uri_default_http_secure 413s END /main/uri/ - uri_default_http_secure Time: <1ms Result: PASS 413s START /main/uri/ - uri_default_http 413s END /main/uri/ - uri_default_http Time: <1ms Result: PASS 413s START /main/uri/ - uri_parse 413s END /main/uri/ - uri_parse Time: <1ms Result: PASS 413s START /main/utf8/ - replace_invalid 413s END /main/utf8/ - replace_invalid Time: <1ms Result: PASS 413s START /main/utf8/ - utf8_validator 413s END /main/utf8/ - utf8_validator Time: <1ms Result: PASS 413s START /main/utf8/ - copy_string 413s END /main/utf8/ - copy_string Time: <1ms Result: PASS 413s START /main/utf8/ - is_valid 413s END /main/utf8/ - is_valid Time: <1ms Result: PASS 413s START /main/utils/ - quote_unescaping 413s END /main/utils/ - quote_unescaping Time: <1ms Result: PASS 413s START /main/utils/ - quote_mutation 413s END /main/utils/ - quote_mutation Time: <1ms Result: PASS 413s START /main/utils/ - crypt_test 413s END /main/utils/ - crypt_test Time: 39ms Result: PASS 413s START /main/utils/ - safe_mkdir_test 413s END /main/utils/ - safe_mkdir_test Time: <1ms Result: PASS 413s START /main/utils/ - base64_test 413s END /main/utils/ - base64_test Time: <1ms Result: PASS 413s START /main/utils/ - sha1_test 413s [test_utils.c:sha1_test:250]: Testing SHA1 ... 413s END /main/utils/ - sha1_test Time: <1ms Result: PASS 413s START /main/utils/ - md5_test 413s [test_utils.c:md5_test:205]: Testing MD5 ... 413s END /main/utils/ - md5_test Time: <1ms Result: PASS 413s START /main/utils/ - quoted_escape_test 413s END /main/utils/ - quoted_escape_test Time: <1ms Result: PASS 413s START /main/utils/ - uri_encode_decode_test 413s END /main/utils/ - uri_encode_decode_test Time: <1ms Result: PASS 413s START /main/utils/ - string_field_aggregate_test 413s [test_stringfields.c:string_field_aggregate_test:392]: Structures 3 embedded pool initialized successfully. 413s [test_stringfields.c:string_field_aggregate_test:410]: Structures 3 additional pool initialized successfully. 413s [test_stringfields.c:string_field_aggregate_test:422]: Structures 1/2 are equal as expected. 413s [test_stringfields.c:string_field_aggregate_test:430]: Structures 1/3 are different as expected. 413s [test_stringfields.c:string_field_aggregate_test:438]: Structures 2/3 are different as expected. 413s [test_stringfields.c:string_field_aggregate_test:446]: Structures 3/4 are different as expected. 413s [test_stringfields.c:string_field_aggregate_test:454]: Copying from structure 3 to structure 1 succeeded! 413s [test_stringfields.c:string_field_aggregate_test:463]: Structures 1/3 are equal as expected. 413s [test_stringfields.c:string_field_aggregate_test:470]: Structures 1/2 are different as expected. 413s [test_stringfields.c:string_field_aggregate_test:473]: Reset but don't free. 413s [test_stringfields.c:string_field_aggregate_test:484]: Structures 1/2 are the same (empty) as expected. 413s [test_stringfields.c:string_field_aggregate_test:492]: Structure 4 embedded pool is the current pool as expected. 413s [test_stringfields.c:string_field_aggregate_test:500]: Structure 4 embedded pool does not have a previous as expected. 413s END /main/utils/ - string_field_aggregate_test Time: <1ms Result: PASS 413s START /main/utils/ - string_field_test 413s [test_stringfields.c:string_field_test:79]: First things first. Let's see if we can actually allocate string fields 413s [test_stringfields.c:string_field_test:85]: All right! Successfully allocated! Now let's get down to business 413s [test_stringfields.c:string_field_test:89]: We're going to set some string fields and perform some checks 413s [test_stringfields.c:string_field_test:94]: First we're going to make sure that the strings are actually set to what we expect 413s [test_stringfields.c:string_field_test:100]: test_struct.string1 appears to be all clear. It has 'elephant' and that's what we expect 413s [test_stringfields.c:string_field_test:107]: test_struct.string2 appears to be all clear. It has 'hippopotamus' and that's what we expect 413s [test_stringfields.c:string_field_test:110]: Now let's make sure that our recorded capacities for these strings is what we expect 413s [test_stringfields.c:string_field_test:117]: string1 has the allocation area we expect: 9 413s [test_stringfields.c:string_field_test:125]: string2 has the allocation area we expect: 13 413s [test_stringfields.c:string_field_test:128]: Now we're going to shrink string1 and see if it's in the same place in memory 413s [test_stringfields.c:string_field_test:137]: string1 successfully was changed to 'rhino' 413s [test_stringfields.c:string_field_test:144]: Shrinking string1 allowed it to stay in the same place in memory 413s [test_stringfields.c:string_field_test:151]: Shrinking string1 did not change its allocation area (This is a good thing) 413s [test_stringfields.c:string_field_test:154]: Next, let's increase it a little but not all the way to its original size 413s [test_stringfields.c:string_field_test:163]: string1 successfully was changed to 'mammoth' 413s [test_stringfields.c:string_field_test:170]: Expanding string1 allowed it to stay in the same place in memory 413s [test_stringfields.c:string_field_test:177]: Expanding string1 did not change its allocation area (This is a good thing) 413s [test_stringfields.c:string_field_test:180]: Cool, now let's bring it back to its original size and see what happens 413s [test_stringfields.c:string_field_test:188]: string1 successfully changed to 'elephant' 413s [test_stringfields.c:string_field_test:195]: Restoring string1 did not cause it to move (This is a good thing) 413s [test_stringfields.c:string_field_test:202]: The allocation amount for string1 is still holding steady 413s [test_stringfields.c:string_field_test:205]: All right, now we're going to expand string 2. It should stay in place since it was the last string allocated in this pool 413s [test_stringfields.c:string_field_test:214]: string2 successfully changed to 'hippopotamus face' 413s [test_stringfields.c:string_field_test:222]: The allocation amount successfully increased for string2 when it grew 413s [test_stringfields.c:string_field_test:229]: string2 stayed in place when it grew. Good job! 413s [test_stringfields.c:string_field_test:232]: Now we're going to set string1 to a very long string so that a new string field pool must be allocated 413s [test_stringfields.c:string_field_test:241]: string1 successfully changed to 'A professional panoramic photograph of the majestic elephant bathing itself and its young by the shores of the raging Mississippi River' 413s [test_stringfields.c:string_field_test:248]: Good. Setting string1 to a long value caused it to change addresses 413s [test_stringfields.c:string_field_test:256]: The stored allocation size of string1 is what we expect 413s [test_stringfields.c:string_field_test:260]: Now using a totally separate area of memory we're going to test a basic pool freeing scenario 413s [test_stringfields.c:string_field_test:281]: Three different pools are linked as expected. 413s [test_stringfields.c:string_field_test:289]: After removing a pool the remaining two are linked as expected. 413s END /main/utils/ - string_field_test Time: <1ms Result: PASS 413s START /main/uuid/ - uuid 413s [test_uuid.c:uuid:59]: Generate UUID direct to string, got e11a8ff0-cc5c-47d3-b0ce-e486e14f7982 413s [test_uuid.c:uuid:90]: Second generated UUID converted to string, got 1a8ac6ae-03e5-4ddb-b9b5-f05f14542863 413s END /main/uuid/ - uuid Time: <1ms Result: PASS 413s START /main/vector/ - basic 413s END /main/vector/ - basic Time: <1ms Result: PASS 413s START /main/vector/ - basic_integer 413s END /main/vector/ - basic_integer Time: <1ms Result: PASS 413s START /main/vector/ - callbacks 413s END /main/vector/ - callbacks Time: <1ms Result: PASS 413s START /main/vector/ - locks 413s END /main/vector/ - locks Time: <1ms Result: PASS 413s START /main/voicemail_api/ - off_nominal_msg_playback 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_1234/Old with ID 1746391273-909401725 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_1234/INBOX with ID 1746391273-960311778 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_2345/INBOX with ID 1746391273-1500739833 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_2345/INBOX with ID 1746391273-719848782 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1502]: Playing back message from invalid mailbox 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1505]: Playing back message from NULL mailbox 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1508]: Playing back message from invalid context 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1511]: Playing back message from invalid folder 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1514]: Playing back message from NULL folder 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1517]: Playing back message with invalid message specifier 413s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1520]: Playing back message with NULL message specifier 413s END /main/voicemail_api/ - off_nominal_msg_playback Time: 9ms Result: PASS 413s START /main/voicemail_api/ - nominal_msg_playback 413s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_1234/Old with ID 1746391273-909401725 413s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_1234/INBOX with ID 1746391273-960311778 413s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_2345/INBOX with ID 1746391273-1500739833 413s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_2345/INBOX with ID 1746391273-719848782 413s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1443]: Playing back message from test_vm_api_1234 to mock channel 414s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1446]: Playing back message from test_vm_api_2345 to callback function 414s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1451]: Playing back message from test_vm_api_2345 to callback function with default context 414s END /main/voicemail_api/ - nominal_msg_playback Time: 454ms Result: PASS 414s START /main/voicemail_api/ - off_nominal_forward 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1362]: Test forwarding from an invalid mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1365]: Test forwarding from a NULL mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1368]: Test forwarding from an invalid context 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1371]: Test forwarding from an invalid folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1374]: Test forwarding from a NULL folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1377]: Test forwarding to an invalid mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1380]: Test forwarding to a NULL mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1383]: Test forwarding to an invalid context 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1386]: Test forwarding to an invalid folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1390]: Test forwarding to a NULL folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1393]: Test forwarding when no messages are select 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1396]: Test forwarding a message that doesn't exist 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1400]: Test forwarding multiple messages, where some messages don't exist 414s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1403]: Test forwarding a message with an invalid size specifier 414s END /main/voicemail_api/ - off_nominal_forward Time: 9ms Result: PASS 414s START /main/voicemail_api/ - nominal_forward 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1244]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1257]: Test forwarding message 0 from test_vm_api_1234 INBOX with default context to test_vm_api_2345 INBOX 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1270]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX with default context 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1283]: Test forwarding message 0 from test_vm_api_1234 INBOX to test_vm_api_2345 INBOX, deleting original 414s [test_voicemail_api.c:voicemail_api_nominal_forward:1296]: Test forwarding 2 messages from test_vm_api_2345 INBOX to test_vm_api_1234 INBOX[test_voicemail_api.c:voicemail_api_nominal_forward:1309]: Test forwarding 2 messages from test_vm_api_2345 INBOX to test_vm_api_1234 Family, deleting original 414s END /main/voicemail_api/ - nominal_forward Time: 28ms Result: PASS 414s START /main/voicemail_api/ - off_nominal_remove 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1184]: Test removing a single message with an invalid mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1187]: Test removing a single message with a NULL mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1190]: Test removing a single message with an invalid context 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1193]: Test removing a single message with an invalid folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1196]: Test removing a single message with a NULL folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1199]: Test removing a single message with an invalid message number 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1203]: Test removing multiple messages with a single invalid message number 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1207]: Test removing no messages with no message numbers 414s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1210]: Test removing multiple messages with an invalid size specifier 414s END /main/voicemail_api/ - off_nominal_remove Time: 9ms Result: PASS 414s START /main/voicemail_api/ - nominal_remove 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1139]: Test removing a single message from INBOX 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1142]: Test removing a single message from Old 414s [test_voicemail_api.c:voicemail_api_nominal_remove:1145]: Test removing multiple messages from INBOX 414s END /main/voicemail_api/ - nominal_remove Time: 11ms Result: PASS 414s START /main/voicemail_api/ - off_nominal_move 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1068]: Test move attempt for invalid mailbox test_vm_3456 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1073]: Test move attempt for invalid context test_vm_api_defunct 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1076]: Test move attempt to invalid folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1079]: Test move attempt from invalid folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1082]: Test move attempt to NULL folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1085]: Test move attempt from NULL folder 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1088]: Test move attempt with non-existent message number 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1092]: Test move attempt with invalid message number 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1096]: Test move attempt with 0 number of messages 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1100]: Test move attempt with invalid number of messages 414s [test_voicemail_api.c:voicemail_api_off_nominal_move:1103]: Test move attempt with non-existent multiple messages, where some messages exist 414s END /main/voicemail_api/ - off_nominal_move Time: 10ms Result: PASS 414s START /main/voicemail_api/ - nominal_move 414s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_nominal_move:992]: Test move of test_vm_api_1234 message from INBOX to Family 414s [test_voicemail_api.c:voicemail_api_nominal_move:995]: Test move of test_vm_api_1234 message from Old to Family 414s [test_voicemail_api.c:voicemail_api_nominal_move:1009]: Test move of test_vm_api_2345 messages from Inbox to Family 414s [test_voicemail_api.c:voicemail_api_nominal_move:1020]: Test move of test_vm_api_2345 message from Family to INBOX 414s END /main/voicemail_api/ - nominal_move Time: 14ms Result: PASS 414s START /main/voicemail_api/ - off_nominal_snapshot 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Test access to non-existent mailbox test_vm_api_3456 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:950]: Test access to null mailbox 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:953]: Test access non-existent context test_vm_api_defunct 414s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:956]: Test non-existent folder test_vm_api_platypus 414s END /main/voicemail_api/ - off_nominal_snapshot Time: 7ms Result: PASS 414s START /main/voicemail_api/ - nominal_snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_1234/Old with ID 1746391274-909401725 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_1234/INBOX with ID 1746391274-960311778 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_2345/INBOX with ID 1746391274-1500739833 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_2345/INBOX with ID 1746391274-719848782 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Test retrieving message 1 from INBOX of test_vm_1234 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:859]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:862]: Test retrieving message 0 from Old of test_vm_1234 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:865]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:868]: Test retrieving message 0, 1 from Old and INBOX of test_vm_1234 ordered by time 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:871]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:872]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:875]: Test retrieving message 1, 0 from Old and INBOX of test_vm_1234 ordered by time desc 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:878]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:879]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:882]: Test retrieving message 0, 1 from Old and INBOX of test_vm_1234 ordered by id 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:885]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:886]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:889]: Test retrieving message 1, 0 from Old and INBOX of test_vm_1234 ordered by id desc 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:892]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:893]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:896]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by id 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:899]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:900]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:903]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by time 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:906]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:907]: Found message 1746391274-960311778 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:910]: Test retrieving message 0, 1 from all folders of test_vm_1234, default context ordered by time 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:913]: Found message 1746391274-909401725 in snapshot 414s [test_voicemail_api.c:voicemail_api_nominal_snapshot:914]: Found message 1746391274-960311778 in snapshot 414s END /main/voicemail_api/ - nominal_snapshot Time: 20ms Result: PASS 414s START /main/xml_escape/ - xml_escape_test 414s END /main/xml_escape/ - xml_escape_test Time: <1ms Result: PASS 414s START /mwi/ - explicit_publish 414s END /mwi/ - explicit_publish Time: 72ms Result: PASS 414s START /mwi/ - implicit_publish 414s END /mwi/ - implicit_publish Time: 71ms Result: PASS 414s START /res/adsi/ - adsi_loaded_test 414s END /res/adsi/ - adsi_loaded_test Time: <1ms Result: PASS 414s START /res/aeap/ - send_msg_handle_request 414s END /res/aeap/ - send_msg_handle_request Time: 2ms Result: PASS 414s START /res/aeap/ - send_msg_handle_response 414s END /res/aeap/ - send_msg_handle_response Time: 1ms Result: PASS 414s START /res/aeap/ - send_msg_handle_string 416s END /res/aeap/ - send_msg_handle_string Time: 2001ms Result: PASS 416s START /res/aeap/ - create_and_connect 416s END /res/aeap/ - create_and_connect Time: <1ms Result: PASS 416s START /res/aeap/speech/ - res_speech_aeap_test 416s END /res/aeap/speech/ - res_speech_aeap_test Time: 1ms Result: PASS 416s START /res/aeap/transaction/ - transaction_exec_timeout 416s END /res/aeap/transaction/ - transaction_exec_timeout Time: 99ms Result: PASS 416s START /res/aeap/transaction/ - transaction_exec 417s END /res/aeap/transaction/ - transaction_exec Time: 1000ms Result: PASS 417s START /res/aeap/transport/ - transport_create_invalid 417s END /res/aeap/transport/ - transport_create_invalid Time: <1ms Result: PASS 417s START /res/aeap/transport/ - transport_create 417s END /res/aeap/transport/ - transport_create Time: <1ms Result: PASS 417s START /res/aeap/transport/ - transport_connect 417s END /res/aeap/transport/ - transport_connect Time: 1ms Result: PASS 417s START /res/aeap/transport/ - transport_connect_fail 417s END /res/aeap/transport/ - transport_connect_fail Time: 1ms Result: PASS 417s START /res/aeap/transport/ - transport_binary 417s END /res/aeap/transport/ - transport_binary Time: 1ms Result: PASS 417s START /res/aeap/transport/ - transport_string 417s END /res/aeap/transport/ - transport_string Time: <1ms Result: PASS 417s START /res/agi/ - agi_loaded_test 417s END /res/agi/ - agi_loaded_test Time: 1ms Result: PASS 417s START /res/agi/ - null_agi_docs 417s END /res/agi/ - null_agi_docs Time: <1ms Result: PASS 417s START /res/ari/ - invoke_not_found 417s END /res/ari/ - invoke_not_found Time: <1ms Result: PASS 417s START /res/ari/ - invoke_bad_post 417s END /res/ari/ - invoke_bad_post Time: <1ms Result: PASS 417s START /res/ari/ - invoke_post 417s END /res/ari/ - invoke_post Time: <1ms Result: PASS 417s START /res/ari/ - invoke_delete 417s END /res/ari/ - invoke_delete Time: <1ms Result: PASS 417s START /res/ari/ - invoke_wildcard 417s END /res/ari/ - invoke_wildcard Time: <1ms Result: PASS 417s START /res/ari/ - invoke_get 417s END /res/ari/ - invoke_get Time: <1ms Result: PASS 417s START /res/ari/ - get_docs_hackerz 417s END /res/ari/ - get_docs_hackerz Time: <1ms Result: PASS 417s START /res/ari/ - get_docs_notfound 417s END /res/ari/ - get_docs_notfound Time: <1ms Result: PASS 417s START /res/ari/ - get_docs_nohost 417s END /res/ari/ - get_docs_nohost Time: <1ms Result: PASS 417s START /res/ari/ - get_docs 417s END /res/ari/ - get_docs Time: <1ms Result: PASS 417s START /res/crypto/ - crypto_loaded_test 417s END /res/crypto/ - crypto_loaded_test Time: <1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_content_type 417s END /res/http_media_cache/ - retrieve_content_type Time: 1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_parsed_uri 417s END /res/http_media_cache/ - retrieve_parsed_uri Time: <1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_cache_control_directives 417s [test_http_media_cache.c:retrieve_cache_control_directives:322]: Testing no-cache... 417s [test_http_media_cache.c:retrieve_cache_control_directives:329]: Testing no-cache with ETag... 417s [test_http_media_cache.c:retrieve_cache_control_directives:339]: Testing no-cache with max-age... 417s [test_http_media_cache.c:retrieve_cache_control_directives:344]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_directives:351]: Testing must-revalidate... 417s [test_http_media_cache.c:retrieve_cache_control_directives:358]: Testing must-revalidate with ETag... 417s [test_http_media_cache.c:retrieve_cache_control_directives:368]: Testing must-revalidate with max-age... 417s [test_http_media_cache.c:retrieve_cache_control_directives:373]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s END /res/http_media_cache/ - retrieve_cache_control_directives Time: 7ms Result: PASS 417s START /res/http_media_cache/ - retrieve_cache_control_age 417s [test_http_media_cache.c:retrieve_cache_control_age:406]: Testing max-age... 417s [test_http_media_cache.c:retrieve_cache_control_age:410]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_age:414]: Testing s-maxage... 417s [test_http_media_cache.c:retrieve_cache_control_age:420]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_age:424]: Testing max-age and s-maxage... 417s [test_http_media_cache.c:retrieve_cache_control_age:430]: Checking 1746391880 >= 1746391877 and 1746391874 <= 1746391877 417s [test_http_media_cache.c:retrieve_cache_control_age:434]: Testing max-age and Expires... 417s [test_http_media_cache.c:retrieve_cache_control_age:441]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_age:445]: Testing s-maxage and Expires... 417s [test_http_media_cache.c:retrieve_cache_control_age:452]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_age:456]: Testing s-maxage and Expires... 417s [test_http_media_cache.c:retrieve_cache_control_age:463]: Checking 1746391580 >= 1746391577 and 1746391574 <= 1746391577 417s [test_http_media_cache.c:retrieve_cache_control_age:467]: Testing max-age, s-maxage, and Expires... 417s [test_http_media_cache.c:retrieve_cache_control_age:474]: Checking 1746391880 >= 1746391877 and 1746391874 <= 1746391877 417s END /res/http_media_cache/ - retrieve_cache_control_age Time: 7ms Result: PASS 417s START /res/http_media_cache/ - retrieve_etag_expired 417s [test_http_media_cache.c:retrieve_etag_expired:514]: Checking 1746391279 >= 1746391276 and 1746391273 <= 1746391276 417s END /res/http_media_cache/ - retrieve_etag_expired Time: 1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_expires 417s [test_http_media_cache.c:retrieve_expires:554]: Checking 1746394280 >= 1746394277 and 1746394274 <= 1746394277 417s [test_http_media_cache.c:retrieve_expires:564]: Checking 1746391279 >= 1746391276 and 1746391273 <= 1746391276 417s END /res/http_media_cache/ - retrieve_expires Time: 1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_etag 417s [test_http_media_cache.c:retrieve_etag:604]: Checking 1746391280 >= 1746391277 and 1746391274 <= 1746391277 417s END /res/http_media_cache/ - retrieve_etag Time: 1ms Result: PASS 417s START /res/http_media_cache/ - retrieve_nominal 417s [test_http_media_cache.c:retrieve_nominal:642]: Checking 1746391280 >= 1746391277 and 1746391274 <= 1746391277 417s END /res/http_media_cache/ - retrieve_nominal Time: <1ms Result: PASS 417s START /res/http_media_cache/ - create_nominal 417s [test_http_media_cache.c:create_nominal:675]: Checking 1746391280 >= 1746391277 and 1746391274 <= 1746391277 417s END /res/http_media_cache/ - create_nominal Time: <1ms Result: PASS 417s START /res/parking/ - dynamic_parking_variables 417s [parking/parking_tests.c:dynamic_parking_variables:756]: Creating expected configuration for dynamic parking lot 417s [parking/parking_tests.c:dynamic_parking_variables:775]: Creating template lot 417s [parking/parking_tests.c:dynamic_parking_variables:784]: Creating Alice channel to test dynamic parking lot creation. 417s [parking/parking_tests.c:dynamic_parking_variables:794]: Setting Dynamic Parking channel variables on Alice. 417s [parking/parking_tests.c:dynamic_parking_variables:802]: Generating dynamic parking lot based on Alice's channel variables. 417s [parking/parking_tests.c:dynamic_parking_variables:819]: Dynamic parking lot created successfully and matches expectations. Test passed. 417s END /res/parking/ - dynamic_parking_variables Time: <1ms Result: PASS 417s START /res/parking/ - extension_conflicts 417s [parking/parking_tests.c:extension_conflicts:597]: Creating the base lot. This should pass. 417s [parking/parking_tests.c:extension_conflicts:607]: Creating a test lot which will overlap. 417s [parking/parking_tests.c:generate_test_parking_lot:161]: Extensions for parking lot 'unit_tests_res_parking_test_lot_fail1' could not be registered. Extension Creation failed. 417s [parking/parking_tests.c:generate_test_parking_lot:161]: Extensions for parking lot 'unit_tests_res_parking_test_lot_fail2' could not be registered. Extension Creation failed. 417s [parking/parking_tests.c:generate_test_parking_lot:161]: Extensions for parking lot 'unit_tests_res_parking_test_lot_fail3' could not be registered. Extension Creation failed. 417s [parking/parking_tests.c:generate_test_parking_lot:161]: Extensions for parking lot 'unit_tests_res_parking_test_lot_fail4' could not be registered. Extension Creation failed. 417s END /res/parking/ - extension_conflicts Time: <1ms Result: PASS 417s START /res/parking/ - park_extensions 417s [parking/parking_tests.c:park_extensions:551]: Extensions for the test parking lot were verified. Cleaning up and verifying their removal. 417s [parking/parking_tests.c:park_extensions:565]: Extensions for the test parking lot verified as removed. Test completed successfully. 417s END /res/parking/ - park_extensions Time: <1ms Result: PASS 417s START /res/parking/ - park_retrieve 417s [parking/parking_tests.c:retrieve_call:405]: Creating test parking lot 'unit_tests_res_parking_test_lot' 418s [parking/parking_tests.c:retrieve_call:446]: Successfully retrieved parked user from the parking lot. Validating user data. 418s END /res/parking/ - park_retrieve Time: 1001ms Result: PASS 418s START /res/parking/ - park_channel 418s [parking/parking_tests.c:park_call:254]: Creating test parking lot 'unit_tests_res_parking_test_lot' 419s END /res/parking/ - park_channel Time: 1001ms Result: PASS 419s START /res/parking/ - create_lot 419s [parking/parking_tests.c:create_lot:206]: Creating test parking lot 'unit_tests_res_parking_test_lot' 419s [parking/parking_tests.c:create_lot:214]: Successfully created parking lot. Retrieving test parking lot from container. 419s [parking/parking_tests.c:create_lot:223]: Successfully retrieved parking lot. Removing test parking lot from container. 419s [parking/parking_tests.c:create_lot:229]: Parking lot was successfully removed from the container. Test complete. 419s END /res/parking/ - create_lot Time: <1ms Result: PASS 419s START /res/prometheus/ - bridge_to_string 419s [test_res_prometheus.c:bridge_to_string:760]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 419s # TYPE asterisk_channels_count gauge 419s asterisk_channels_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_sum Total call count. 419s # TYPE asterisk_calls_sum counter 419s asterisk_calls_sum{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_count Current call count. 419s # TYPE asterisk_calls_count gauge 419s asterisk_calls_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_endpoints_count Current endpoint count. 419s # TYPE asterisk_endpoints_count gauge 419s asterisk_endpoints_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_bridges_count Current bridge count. 419s # TYPE asterisk_bridges_count gauge 419s asterisk_bridges_count{eid="00:16:3e:77:53:de"} 3 419s # HELP asterisk_bridges_channels_count Number of channels in the bridge. 419s # TYPE asterisk_bridges_channels_count gauge 419s asterisk_bridges_channels_count{eid="00:16:3e:77:53:de",id="ad6ea949-8fa0-4b61-9d89-e241c47b32c8",tech="simple_bridge",subclass="basic",creator="",name=""} 0 419s asterisk_bridges_channels_count{eid="00:16:3e:77:53:de",id="f6c8a9a6-5d24-484d-a2e5-cdd080a3575a",tech="simple_bridge",subclass="basic",creator="",name=""} 0 419s 419s END /res/prometheus/ - bridge_to_string Time: <1ms Result: PASS 419s START /res/prometheus/ - config_general_core_metrics 419s [test_res_prometheus.c:config_general_core_metrics:680]: -> CURLing request... 419s [test_res_prometheus.c:config_general_core_metrics:688]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 419s # TYPE asterisk_channels_count gauge 419s asterisk_channels_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_sum Total call count. 419s # TYPE asterisk_calls_sum counter 419s asterisk_calls_sum{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_count Current call count. 419s # TYPE asterisk_calls_count gauge 419s asterisk_calls_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_endpoints_count Current endpoint count. 419s # TYPE asterisk_endpoints_count gauge 419s asterisk_endpoints_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_bridges_count Current bridge count. 419s # TYPE asterisk_bridges_count gauge 419s asterisk_bridges_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_core_properties Asterisk instance properties. The value of this will always be 1. 419s # TYPE asterisk_core_properties counter 419s asterisk_core_properties{eid="00:16:3e:77:53:de",version="22.2.0~dfsg+~cs6.15.60671435-2",build_options="OPTIONAL_API, TEST_FRAMEWORK",build_date="2025-02-22 07:54:51 UTC",build_os="Linux",build_kernel="unknown",build_host="buildd.debian.org"} 1 419s # HELP asterisk_core_uptime_seconds Asterisk instance uptime in seconds. 419s # TYPE asterisk_core_uptime_seconds counter 419s asterisk_core_uptime_seconds{eid="00:16:3e:77:53:de"} 178 419s # HELP asterisk_core_last_reload_seconds Time since last Asterisk reload in seconds. 419s # TYPE asterisk_core_last_reload_seconds counter 419s asterisk_core_last_reload_seconds{eid="00:16:3e:77:53:de"} 178 419s # HELP asterisk_core_scrape_time_ms Total time taken to collect metrics, in milliseconds 419s # TYPE asterisk_core_scrape_time_ms counter 419s asterisk_core_scrape_time_ms{eid="00:16:3e:77:53:de"} 0 419s 419s [test_res_prometheus.c:config_general_core_metrics:690]: -> Checking for core properties 419s [test_res_prometheus.c:config_general_core_metrics:693]: -> Checking for uptime 419s [test_res_prometheus.c:config_general_core_metrics:696]: -> Checking for last reload 419s [test_res_prometheus.c:config_general_core_metrics:699]: -> Checking for scrape time 419s END /res/prometheus/ - config_general_core_metrics Time: <1ms Result: PASS 419s START /res/prometheus/ - config_general_basic_auth 419s [test_res_prometheus.c:config_general_basic_auth:555]: Testing without auth credentials 419s [test_res_prometheus.c:config_general_basic_auth:556]: -> CURLing request... 419s [test_res_prometheus.c:config_general_basic_auth:563]: -> CURL returned 401 419s [test_res_prometheus.c:config_general_basic_auth:566]: Testing with invalid auth credentials 419s [test_res_prometheus.c:config_general_basic_auth:567]: -> CURLing request... 419s [test_res_prometheus.c:config_general_basic_auth:576]: -> CURL returned 401 419s [test_res_prometheus.c:config_general_basic_auth:579]: Testing with valid auth credentials 419s [test_res_prometheus.c:config_general_basic_auth:580]: -> CURLing request... 419s [test_res_prometheus.c:config_general_basic_auth:588]: -> CURL returned 200 419s END /res/prometheus/ - config_general_basic_auth Time: 1ms Result: PASS 419s START /res/prometheus/ - config_general_enabled 419s [test_res_prometheus.c:config_general_enabled:628]: -> CURLing request... 419s [test_res_prometheus.c:config_general_enabled:635]: -> CURL returned 503 419s END /res/prometheus/ - config_general_enabled Time: <1ms Result: PASS 419s START /res/prometheus/ - gauge_create 419s END /res/prometheus/ - gauge_create Time: <1ms Result: PASS 419s START /res/prometheus/ - gauge_to_string 419s END /res/prometheus/ - gauge_to_string Time: <1ms Result: PASS 419s START /res/prometheus/ - counter_create 419s END /res/prometheus/ - counter_create Time: <1ms Result: PASS 419s START /res/prometheus/ - counter_to_string 419s END /res/prometheus/ - counter_to_string Time: <1ms Result: PASS 419s START /res/prometheus/ - metric_register 419s [test_res_prometheus.c:metric_register:291]: Testing nominal registration 419s [test_res_prometheus.c:metric_register:292]: -> Static metric 419s [test_res_prometheus.c:metric_register:294]: -> Malloc'd metric 419s [test_res_prometheus.c:metric_register:300]: Testing nominal registration of child metrics 419s [test_res_prometheus.c:metric_register:315]: Testing name collisions 419s [test_res_prometheus.c:metric_register:322]: Testing label collisions 419s [test_res_prometheus.c:metric_register:331]: Testing removal of metrics 419s END /res/prometheus/ - metric_register Time: <1ms Result: PASS 419s START /res/prometheus/ - metric_callback_register 419s [test_res_prometheus.c:metric_callback_register:241]: -> CURLing request... 419s [test_res_prometheus.c:metric_callback_register:250]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 419s # TYPE asterisk_channels_count gauge 419s asterisk_channels_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_sum Total call count. 419s # TYPE asterisk_calls_sum counter 419s asterisk_calls_sum{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_count Current call count. 419s # TYPE asterisk_calls_count gauge 419s asterisk_calls_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_endpoints_count Current endpoint count. 419s # TYPE asterisk_endpoints_count gauge 419s asterisk_endpoints_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_bridges_count Current bridge count. 419s # TYPE asterisk_bridges_count gauge 419s asterisk_bridges_count{eid="00:16:3e:77:53:de"} 0 419s # HELP test_counter A test counter 419s # TYPE test_counter counter 419s test_counter 0 419s 419s END /res/prometheus/ - metric_callback_register Time: <1ms Result: PASS 419s START /res/prometheus/ - metric_values 419s [test_res_prometheus.c:metric_values:166]: -> CURLing request... 419s [test_res_prometheus.c:metric_values:176]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 419s # TYPE asterisk_channels_count gauge 419s asterisk_channels_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_sum Total call count. 419s # TYPE asterisk_calls_sum counter 419s asterisk_calls_sum{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_calls_count Current call count. 419s # TYPE asterisk_calls_count gauge 419s asterisk_calls_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_endpoints_count Current endpoint count. 419s # TYPE asterisk_endpoints_count gauge 419s asterisk_endpoints_count{eid="00:16:3e:77:53:de"} 0 419s # HELP asterisk_bridges_count Current bridge count. 419s # TYPE asterisk_bridges_count gauge 419s asterisk_bridges_count{eid="00:16:3e:77:53:de"} 0 419s # HELP test_counter_one A test counter 419s # TYPE test_counter_one counter 419s test_counter_one 1 419s # HELP test_counter_two A test counter 419s # TYPE test_counter_two counter 419s test_counter_two 2 419s 419s END /res/prometheus/ - metric_values Time: <1ms Result: PASS 419s START /res/res_crypto/ - crypto_aes_decrypt 419s [test_crypto.c:crypto_aes_decrypt:607]: Executing AES-ECB decryption test 419s END /res/res_crypto/ - crypto_aes_decrypt Time: 25ms Result: PASS 419s START /res/res_crypto/ - crypto_aes_encrypt 419s [test_crypto.c:crypto_aes_encrypt:531]: Executing AES-ECB encryption test 419s END /res/res_crypto/ - crypto_aes_encrypt Time: 19ms Result: PASS 419s START /res/res_crypto/ - crypto_verify 419s [test_crypto.c:crypto_verify:425]: Executing RSA signature verification test 419s [test_crypto.c:crypto_verify:456]: Couldn't read key: rsa_key1 419s END /res/res_crypto/ - crypto_verify Time: <1ms Result: FAIL 419s START /res/res_crypto/ - crypto_sign 419s [test_crypto.c:crypto_sign:306]: Executing RSA signing test 419s [test_crypto.c:crypto_sign:341]: Couldn't read key: rsa_key1 419s END /res/res_crypto/ - crypto_sign Time: <1ms Result: FAIL 419s START /res/res_crypto/ - crypto_decrypt_pub_key 419s [test_crypto.c:crypto_rsa_decrypt:203]: Executing RSA decryption test 419s [test_crypto.c:crypto_rsa_decrypt:231]: Couldn't read key: rsa_key1 419s END /res/res_crypto/ - crypto_decrypt_pub_key Time: <1ms Result: FAIL 419s START /res/res_crypto/ - crypto_rsa_encrypt 419s [test_crypto.c:crypto_rsa_encrypt:107]: Executing RSA encryption test 419s [test_crypto.c:crypto_rsa_encrypt:138]: Couldn't read key: rsa_key1 419s END /res/res_crypto/ - crypto_rsa_encrypt Time: <1ms Result: FAIL 419s START /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test 419s END /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test Time: <1ms Result: PASS 419s START /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test 419s END /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test Time: <1ms Result: PASS 419s START /res/res_pjsip/ - xml_sanitization_exceeds_buffer 419s END /res/res_pjsip/ - xml_sanitization_exceeds_buffer Time: <1ms Result: PASS 419s START /res/res_pjsip/ - xml_sanitization_end_null 419s END /res/res_pjsip/ - xml_sanitization_end_null Time: <1ms Result: PASS 419s START /res/res_pjsip/scheduler/ - scheduler_policy 419s [test_res_pjsip_scheduler.c:scheduler_policy:355]: This test will take about 4.5 seconds 424s END /res/res_pjsip/scheduler/ - scheduler_policy Time: 4499ms Result: PASS 424s START /res/res_pjsip/scheduler/ - scheduler_cancel 424s [test_res_pjsip_scheduler.c:scheduler_cancel:301]: This test will take about 1.5 seconds 425s END /res/res_pjsip/scheduler/ - scheduler_cancel Time: 1500ms Result: PASS 425s START /res/res_pjsip/scheduler/ - scheduler_cleanup 425s [test_res_pjsip_scheduler.c:scheduler_cleanup:250]: This test will take about 1.6 seconds 427s END /res/res_pjsip/scheduler/ - scheduler_cleanup Time: 1600ms Result: PASS 427s START /res/res_pjsip/scheduler/ - unserialized_scheduler 427s [test_res_pjsip_scheduler.c:scheduler:136]: This test will take about 3.0 seconds 430s END /res/res_pjsip/scheduler/ - unserialized_scheduler Time: 2999ms Result: PASS 430s START /res/res_pjsip/scheduler/ - serialized_scheduler 430s [test_res_pjsip_scheduler.c:scheduler:131]: This test will take about 4.0 seconds 434s END /res/res_pjsip/scheduler/ - serialized_scheduler Time: 3999ms Result: PASS 434s START /res/res_pjsip_pubsub/ - bad_event 434s END /res/res_pjsip_pubsub/ - bad_event Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - loop 434s END /res/res_pjsip_pubsub/ - loop Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - duplicate_resource 434s END /res/res_pjsip_pubsub/ - duplicate_resource Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - bad_branch 434s END /res/res_pjsip_pubsub/ - bad_branch Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - bad_resource 434s END /res/res_pjsip_pubsub/ - bad_resource Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - complex_resource_tree 434s END /res/res_pjsip_pubsub/ - complex_resource_tree Time: <1ms Result: PASS 434s START /res/res_pjsip_pubsub/ - resource_tree 434s END /res/res_pjsip_pubsub/ - resource_tree Time: <1ms Result: PASS 434s START /res/res_pjsip_session/ - merge_refresh_topologies 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5892]: Test 1 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5912]: Test 2 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5936]: Test 3 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5955]: Test 4 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5973]: Test 5 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:5994]: Test 6 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6020]: Test 7 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6041]: Test 8 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6061]: Test 9 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6081]: Test 10 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6104]: Test 11 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6129]: Test 12 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6163]: Test 13 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6187]: Test 14 passed 434s [res_pjsip_session.c:test_resolve_refresh_media_states:6211]: Test 15 passed 434s END /res/res_pjsip_session/ - merge_refresh_topologies Time: <1ms Result: PASS 434s START /res/res_pjsip_session/caps/ - low_level 434s [test_res_pjsip_session_caps.c:low_level:134]: Testing incoming expected pass 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (local ), outgoing: (no ), expected: (alaw,g722) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (local_first ), outgoing: (no ), expected: (alaw) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (slin), remote: (all), pref: (local ), outgoing: (no ), expected: (slin) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (remote ), outgoing: (no ), expected: (g722,alaw) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (remote_first), outgoing: (no ), expected: (g722) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (all), remote: (slin), pref: (remote_first), outgoing: (no ), expected: (slin) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:low_level:142]: Testing incoming expected fail 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g729), pref: (local ), outgoing: (no ), expected: () expected result: (FAIL) 434s [test_res_pjsip_session_caps.c:test_create_joint:102]: Expected Failure: Expected: () Actual: (nothing) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (local_merge ), outgoing: (no ), expected: () expected result: (FAIL) 434s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,alaw,g729), pref: (remote_merge), outgoing: (no ), expected: () expected result: (FAIL) 434s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 434s [test_res_pjsip_session_caps.c:low_level:147]: Testing outgoing expected pass 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (local ), outgoing: (yes), expected: (alaw,g722) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (local_first ), outgoing: (yes), expected: (alaw) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (local_merge ), outgoing: (yes), expected: (ulaw,alaw,g722) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (remote ), outgoing: (yes), expected: (g722,alaw) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (remote_first), outgoing: (yes), expected: (g722) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (ulaw,alaw,g722), remote: (g722,g729,alaw), pref: (remote_merge), outgoing: (yes), expected: (g722,alaw,ulaw) expected result: (PASS) 434s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (!all), remote: (g722,g729,alaw), pref: (remote_merge), outgoing: (yes), expected: (nothing) expected result: (PASS) 434s END /res/res_pjsip_session/caps/ - low_level Time: 2ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_srv 434s END /res/res_resolver_unbound/ - resolve_srv Time: 10ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_naptr 434s END /res/res_resolver_unbound/ - resolve_naptr Time: <1ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_cancel_off_nominal 434s END /res/res_resolver_unbound/ - resolve_cancel_off_nominal Time: 16ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_async_off_nominal 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query 'duck.feathers', type 1 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query 'goose.feathers', type 28 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query 'goose.feathers', type 1 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query '.1', type 1 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query '.www', type 1 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query '.1', type 12 434s [res_resolver_unbound.c:off_nominal_async_run:1010]: Performing DNS query '.www', type 12 434s END /res/res_resolver_unbound/ - resolve_async_off_nominal Time: <1ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_sync_off_nominal 434s END /res/res_resolver_unbound/ - resolve_sync_off_nominal Time: <1ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_async 434s [res_resolver_unbound.c:nominal_async_run:727]: Performing DNS query 'goose.feathers', type 1 434s [res_resolver_unbound.c:nominal_async_run:727]: Performing DNS query 'goose.feathers', type 28 434s [res_resolver_unbound.c:nominal_async_run:727]: Performing DNS query 'duck.feathers', type 1 434s END /res/res_resolver_unbound/ - resolve_async Time: <1ms Result: PASS 434s START /res/res_resolver_unbound/ - resolve_sync 434s [res_resolver_unbound.c:nominal_sync_run:577]: Performing DNS query 'goose.feathers', type 1 434s [res_resolver_unbound.c:nominal_sync_run:577]: Performing DNS query 'goose.feathers', type 28 434s [res_resolver_unbound.c:nominal_sync_run:577]: Performing DNS query 'duck.feathers', type 1 434s END /res/res_resolver_unbound/ - resolve_sync Time: <1ms Result: PASS 434s START /res/res_rtp/ - fir_nominal 434s END /res/res_rtp/ - fir_nominal Time: 2ms Result: PASS 434s START /res/res_rtp/ - sr_rr_nominal 434s END /res/res_rtp/ - sr_rr_nominal Time: 1ms Result: PASS 434s START /res/res_rtp/ - remb_nominal 434s END /res/res_rtp/ - remb_nominal Time: 1ms Result: PASS 434s START /res/res_rtp/ - lost_packet_stats_nominal 434s END /res/res_rtp/ - lost_packet_stats_nominal Time: 1ms Result: PASS 434s START /res/res_rtp/ - nack_overflow 434s END /res/res_rtp/ - nack_overflow Time: 1ms Result: PASS 434s START /res/res_rtp/ - nack_nominal 434s END /res/res_rtp/ - nack_nominal Time: 1ms Result: PASS 434s START /res/res_rtp/ - nack_no_packet_loss 434s END /res/res_rtp/ - nack_no_packet_loss Time: 1ms Result: PASS 434s START /res/res_sorcery_memory_cache/ - full_backend_cache_stale 449s END /res/res_sorcery_memory_cache/ - full_backend_cache_stale Time: 15001ms Result: PASS 449s START /res/res_sorcery_memory_cache/ - full_backend_cache_expiration 454s END /res/res_sorcery_memory_cache/ - full_backend_cache_expiration Time: 5000ms Result: PASS 454s START /res/res_sorcery_memory_cache/ - expiration 459s END /res/res_sorcery_memory_cache/ - expiration Time: 5000ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - maximum_objects 459s END /res/res_sorcery_memory_cache/ - maximum_objects Time: 4ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - delete 459s END /res/res_sorcery_memory_cache/ - delete Time: <1ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - create 459s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - create 459s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - open_with_invalid_options 459s END /res/res_sorcery_memory_cache/ - open_with_invalid_options Time: <1ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - open_with_valid_options 459s END /res/res_sorcery_memory_cache/ - open_with_valid_options Time: <1ms Result: PASS 459s START /res/res_sorcery_memory_cache/ - stale 459s [res_sorcery_memory_cache.c:stale:3204]: Begininning iteration 0 464s [res_sorcery_memory_cache.c:stale:3204]: Begininning iteration 1 469s [res_sorcery_memory_cache.c:stale:3204]: Begininning iteration 2 474s END /res/res_sorcery_memory_cache/ - stale Time: 15001ms Result: PASS 474s START /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration 477s END /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration Time: 3021ms Result: PASS 477s START /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale 483s END /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale Time: 6006ms Result: PASS 483s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale 489s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale Time: 6010ms Result: PASS 489s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum 492s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum Time: 3013ms Result: PASS 492s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates 495s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates Time: 3007ms Result: PASS 495s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire 498s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire Time: 3013ms Result: PASS 498s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale 501s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale Time: 3006ms Result: PASS 501s START /res/sorcery_astdb/ - object_delete_uncreated 501s END /res/sorcery_astdb/ - object_delete_uncreated Time: 1ms Result: PASS 501s START /res/sorcery_astdb/ - object_delete 501s END /res/sorcery_astdb/ - object_delete Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_update_uncreated 501s END /res/sorcery_astdb/ - object_update_uncreated Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_update 501s END /res/sorcery_astdb/ - object_update Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_retrieve_regex 501s END /res/sorcery_astdb/ - object_retrieve_regex Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_retrieve_multiple_field 501s END /res/sorcery_astdb/ - object_retrieve_multiple_field Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_retrieve_multiple_all 501s END /res/sorcery_astdb/ - object_retrieve_multiple_all Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_retrieve_field 501s END /res/sorcery_astdb/ - object_retrieve_field Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_retrieve_id 501s END /res/sorcery_astdb/ - object_retrieve_id Time: <1ms Result: PASS 501s START /res/sorcery_astdb/ - object_create 501s END /res/sorcery_astdb/ - object_create Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_filter 501s END /res/sorcery_realtime/ - object_filter Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_allocate_on_retrieval 501s END /res/sorcery_realtime/ - object_allocate_on_retrieval Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_delete_uncreated 501s END /res/sorcery_realtime/ - object_delete_uncreated Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_delete 501s END /res/sorcery_realtime/ - object_delete Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_update 501s END /res/sorcery_realtime/ - object_update Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_regex_nofetch 501s END /res/sorcery_realtime/ - object_retrieve_regex_nofetch Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_regex 501s END /res/sorcery_realtime/ - object_retrieve_regex Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_multiple_field 501s END /res/sorcery_realtime/ - object_retrieve_multiple_field Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch 501s END /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_multiple_all 501s END /res/sorcery_realtime/ - object_retrieve_multiple_all Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_field 501s END /res/sorcery_realtime/ - object_retrieve_field Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_retrieve_id 501s END /res/sorcery_realtime/ - object_retrieve_id Time: <1ms Result: PASS 501s START /res/sorcery_realtime/ - object_create 501s END /res/sorcery_realtime/ - object_create Time: <1ms Result: PASS 501s START /res/websocket/ - websocket_client_multiple_protocols 501s END /res/websocket/ - websocket_client_multiple_protocols Time: <1ms Result: PASS 501s START /res/websocket/ - websocket_client_unsupported_protocol 501s END /res/websocket/ - websocket_client_unsupported_protocol Time: <1ms Result: PASS 501s START /res/websocket/ - websocket_client_bad_url 501s END /res/websocket/ - websocket_client_bad_url Time: 2ms Result: PASS 501s START /stasis/channels/ - channel_redirect_snapshot_json 501s END /stasis/channels/ - channel_redirect_snapshot_json Time: <1ms Result: PASS 501s START /stasis/channels/ - channel_snapshot_json 501s END /stasis/channels/ - channel_snapshot_json Time: <1ms Result: PASS 501s START /stasis/channels/ - multi_channel_blob_snapshots 501s END /stasis/channels/ - multi_channel_blob_snapshots Time: <1ms Result: PASS 501s START /stasis/channels/ - multi_channel_blob_create 501s END /stasis/channels/ - multi_channel_blob_create Time: <1ms Result: PASS 501s START /stasis/channels/ - null_blob 501s END /stasis/channels/ - null_blob Time: <1ms Result: PASS 501s START /stasis/channels/ - channel_blob_create 501s END /stasis/channels/ - channel_blob_create Time: <1ms Result: PASS 501s START /stasis/core/ - caching_dtor_order 501s END /stasis/core/ - caching_dtor_order Time: <1ms Result: PASS 501s START /stasis/core/ - dtor_order 501s END /stasis/core/ - dtor_order Time: <1ms Result: PASS 501s START /stasis/core/ - to_ami 501s END /stasis/core/ - to_ami Time: <1ms Result: PASS 501s START /stasis/core/ - no_to_ami 501s END /stasis/core/ - no_to_ami Time: <1ms Result: PASS 501s START /stasis/core/ - to_json 501s END /stasis/core/ - to_json Time: <1ms Result: PASS 501s START /stasis/core/ - no_to_json 501s END /stasis/core/ - no_to_json Time: <1ms Result: PASS 501s START /stasis/core/ - subscription_interleaving 501s END /stasis/core/ - subscription_interleaving Time: <1ms Result: PASS 501s START /stasis/core/ - interleaving 501s END /stasis/core/ - interleaving Time: <1ms Result: PASS 501s START /stasis/core/ - router_cache_updates 501s END /stasis/core/ - router_cache_updates Time: 100ms Result: PASS 501s START /stasis/core/ - router_pool 501s END /stasis/core/ - router_pool Time: <1ms Result: PASS 501s START /stasis/core/ - router 501s END /stasis/core/ - router Time: <1ms Result: PASS 501s START /stasis/core/ - cache_eid_aggregate 501s END /stasis/core/ - cache_eid_aggregate Time: 1ms Result: PASS 501s START /stasis/core/ - cache_dump 501s END /stasis/core/ - cache_dump Time: <1ms Result: PASS 501s START /stasis/core/ - cache 501s END /stasis/core/ - cache Time: <1ms Result: PASS 501s START /stasis/core/ - cache_filter 501s END /stasis/core/ - cache_filter Time: 100ms Result: PASS 501s START /stasis/core/ - forward 501s END /stasis/core/ - forward Time: <1ms Result: PASS 501s START /stasis/core/ - unsubscribe_stops_messages 501s END /stasis/core/ - unsubscribe_stops_messages Time: 100ms Result: PASS 501s START /stasis/core/ - publish_pool 501s END /stasis/core/ - publish_pool Time: <1ms Result: PASS 501s START /stasis/core/ - publish_sync 501s END /stasis/core/ - publish_sync Time: <1ms Result: PASS 501s START /stasis/core/ - publish 501s END /stasis/core/ - publish Time: <1ms Result: PASS 501s START /stasis/core/ - subscription_pool_messages 501s END /stasis/core/ - subscription_pool_messages Time: <1ms Result: PASS 501s START /stasis/core/ - subscription_messages 501s END /stasis/core/ - subscription_messages Time: <1ms Result: PASS 501s START /stasis/core/ - message 501s END /stasis/core/ - message Time: <1ms Result: PASS 501s START /stasis/core/ - message_type 501s END /stasis/core/ - message_type Time: <1ms Result: PASS 501s START /stasis/core/filtering/ - combo_filters 501s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 501s END /stasis/core/filtering/ - combo_filters Time: <1ms Result: PASS 501s START /stasis/core/filtering/ - formatter_filters 501s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass2 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageEVENT Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 501s END /stasis/core/filtering/ - formatter_filters Time: <1ms Result: PASS 501s START /stasis/core/filtering/ - type_filters 501s [test_stasis.c:dump_consumer:2198]: Messages received: 5 Final? yes 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 501s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass2 501s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 501s END /stasis/core/filtering/ - type_filters Time: <1ms Result: PASS 501s START /stasis/core/state/ - explicit_publish 501s END /stasis/core/state/ - explicit_publish Time: 78ms Result: PASS 501s START /stasis/core/state/ - implicit_publish 501s END /stasis/core/state/ - implicit_publish Time: 67ms Result: PASS 501s START /stasis/endpoints/ - channel_messages 501s END /stasis/endpoints/ - channel_messages Time: 1ms Result: PASS 501s START /stasis/endpoints/ - cache_clear 501s END /stasis/endpoints/ - cache_clear Time: <1ms Result: PASS 501s START /stasis/endpoints/ - state_changes 501s END /stasis/endpoints/ - state_changes Time: <1ms Result: PASS 501s START /stasis/res/ - app_invoke_dne 501s END /stasis/res/ - app_invoke_dne Time: <1ms Result: PASS 501s START /stasis/res/ - app_invoke_one 501s END /stasis/res/ - app_invoke_one Time: <1ms Result: PASS 501s START /stasis/res/ - app_replaced 501s END /stasis/res/ - app_replaced Time: <1ms Result: PASS 501s 501s 659 Test(s) Executed 654 Passed 5 Failed 501s 'U' option is not compatible with remote console mode and has no effect. 501s 501s Results Generated Successfully: /tmp/autopkgtest.QeFSol/build.FwO/src/debian/tests/testmods/output/results.txt 501s 'U' option is not compatible with remote console mode and has no effect. 501s 501s Some test modules were not loaded: 501s 20a21 501s > test_cel.so 501s 53a55 501s > test_message.so 501s Manually disabled: 501s test_message 501s test_cel 501s 501s 'U' option is not compatible with remote console mode and has no effect. 501s 503s autopkgtest [20:42:43]: test asttestmods: -----------------------] 507s autopkgtest [20:42:47]: test asttestmods: - - - - - - - - - - results - - - - - - - - - - 507s asttestmods PASS 510s autopkgtest [20:42:50]: test amr: preparing testbed 533s autopkgtest [20:43:13]: testbed dpkg architecture: armhf 535s autopkgtest [20:43:15]: testbed apt version: 3.0.0 539s autopkgtest [20:43:19]: @@@@@@@@@@@@@@@@@@@@ test bed setup 541s autopkgtest [20:43:21]: testbed release detected to be: questing 548s autopkgtest [20:43:28]: updating testbed package index (apt update) 550s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 550s Get:2 http://ftpmaster.internal/ubuntu questing InRelease [110 kB] 551s Get:3 http://ftpmaster.internal/ubuntu questing-updates InRelease [110 kB] 551s Get:4 http://ftpmaster.internal/ubuntu questing-security InRelease [110 kB] 551s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [33.9 kB] 551s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [1095 kB] 551s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [111 kB] 551s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main armhf Packages [132 kB] 551s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe armhf Packages [1019 kB] 551s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse armhf Packages [28.4 kB] 551s Get:11 http://ftpmaster.internal/ubuntu questing/multiverse Sources [306 kB] 551s Get:12 http://ftpmaster.internal/ubuntu questing/universe Sources [21.3 MB] 552s Get:13 http://ftpmaster.internal/ubuntu questing/main Sources [1395 kB] 552s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf Packages [1358 kB] 552s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf Packages [15.3 MB] 553s Get:16 http://ftpmaster.internal/ubuntu questing/multiverse armhf Packages [180 kB] 556s Fetched 42.7 MB in 6s (7271 kB/s) 558s Reading package lists... 563s autopkgtest [20:43:43]: upgrading testbed (apt dist-upgrade and autopurge) 565s Reading package lists... 565s Building dependency tree... 565s Reading state information... 566s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 566s Starting 2 pkgProblemResolver with broken count: 0 566s Done 567s Entering ResolveByKeep 568s 568s Calculating upgrade... 569s The following packages will be upgraded: 569s base-files base-passwd cloud-init cloud-init-base debianutils 569s distro-info-data dpkg dpkg-dev ed ethtool fwupd htop iso-codes libbpf1 569s libdpkg-perl libevdev2 libftdi1-2 libfwupd3 libjcat1 libmbim-glib4 569s libmbim-proxy libmm-glib0 libnftnl11 libnghttp2-14 libnpth0t64 libnvme1t64 569s libqmi-glib5 libqmi-proxy libsensors-config libsensors5 libsepol2 569s libsqlite3-0 libunistring5 liburcu8t64 libusb-1.0-0 man-db motd-news-config 569s nano patch publicsuffix python3-lazr.restfulclient python3-more-itertools 569s python3-s3transfer sos ubuntu-pro-client ubuntu-pro-client-l10n usb.ids 569s usbutils 569s 48 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 569s Need to get 15.6 MB of archives. 569s After this operation, 1221 kB disk space will be freed. 569s Get:1 http://ftpmaster.internal/ubuntu questing/main armhf motd-news-config all 13.7ubuntu1 [5260 B] 569s Get:2 http://ftpmaster.internal/ubuntu questing/main armhf base-files armhf 13.7ubuntu1 [75.4 kB] 569s Get:3 http://ftpmaster.internal/ubuntu questing/main armhf debianutils armhf 5.22 [92.2 kB] 569s Get:4 http://ftpmaster.internal/ubuntu questing/main armhf dpkg armhf 1.22.18ubuntu3 [1254 kB] 569s Get:5 http://ftpmaster.internal/ubuntu questing/main armhf base-passwd armhf 3.6.7 [53.9 kB] 569s Get:6 http://ftpmaster.internal/ubuntu questing/main armhf libsepol2 armhf 3.8.1-1 [282 kB] 569s Get:7 http://ftpmaster.internal/ubuntu questing/main armhf libnpth0t64 armhf 1.8-3 [7716 B] 569s Get:8 http://ftpmaster.internal/ubuntu questing/main armhf distro-info-data all 0.64 [6664 B] 569s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf iso-codes all 4.18.0-1 [3703 kB] 569s Get:10 http://ftpmaster.internal/ubuntu questing/main armhf libbpf1 armhf 1:1.5.0-3 [158 kB] 569s Get:11 http://ftpmaster.internal/ubuntu questing-proposed/main armhf libsqlite3-0 armhf 3.46.1-4 [602 kB] 570s Get:12 http://ftpmaster.internal/ubuntu questing/main armhf libunistring5 armhf 1.3-2 [583 kB] 570s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client-l10n armhf 35.1ubuntu0 [19.7 kB] 570s Get:14 http://ftpmaster.internal/ubuntu questing/main armhf ubuntu-pro-client armhf 35.1ubuntu0 [258 kB] 570s Get:15 http://ftpmaster.internal/ubuntu questing/main armhf ed armhf 1.21.1-1 [53.0 kB] 570s Get:16 http://ftpmaster.internal/ubuntu questing/main armhf ethtool armhf 1:6.14-2 [230 kB] 570s Get:17 http://ftpmaster.internal/ubuntu questing/main armhf libevdev2 armhf 1.13.4+dfsg-1 [29.8 kB] 570s Get:18 http://ftpmaster.internal/ubuntu questing/main armhf libnftnl11 armhf 1.2.9-1 [53.3 kB] 570s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf libnghttp2-14 armhf 1.64.0-1.1 [68.5 kB] 570s Get:20 http://ftpmaster.internal/ubuntu questing/main armhf libsensors-config all 1:3.6.2-2 [6756 B] 570s Get:21 http://ftpmaster.internal/ubuntu questing/main armhf libsensors5 armhf 1:3.6.2-2 [26.8 kB] 570s Get:22 http://ftpmaster.internal/ubuntu questing/main armhf liburcu8t64 armhf 0.15.2-2 [57.3 kB] 570s Get:23 http://ftpmaster.internal/ubuntu questing/main armhf libusb-1.0-0 armhf 2:1.0.28-1 [50.0 kB] 570s Get:24 http://ftpmaster.internal/ubuntu questing/main armhf man-db armhf 2.13.1-1 [1341 kB] 570s Get:25 http://ftpmaster.internal/ubuntu questing/main armhf nano armhf 8.4-1 [278 kB] 570s Get:26 http://ftpmaster.internal/ubuntu questing/main armhf publicsuffix all 20250328.1952-0.1 [135 kB] 570s Get:27 http://ftpmaster.internal/ubuntu questing/main armhf usb.ids all 2025.04.01-1 [223 kB] 570s Get:28 http://ftpmaster.internal/ubuntu questing/main armhf usbutils armhf 1:018-2 [77.4 kB] 570s Get:29 http://ftpmaster.internal/ubuntu questing/main armhf cloud-init-base all 25.2~1g7a0265d3-0ubuntu1 [619 kB] 570s Get:30 http://ftpmaster.internal/ubuntu questing/main armhf dpkg-dev all 1.22.18ubuntu3 [1089 kB] 570s Get:31 http://ftpmaster.internal/ubuntu questing/main armhf libdpkg-perl all 1.22.18ubuntu3 [281 kB] 570s Get:32 http://ftpmaster.internal/ubuntu questing/main armhf patch armhf 2.8-1 [94.1 kB] 570s Get:33 http://ftpmaster.internal/ubuntu questing/main armhf libjcat1 armhf 0.2.3-1 [30.9 kB] 570s Get:34 http://ftpmaster.internal/ubuntu questing/main armhf fwupd armhf 2.0.8-3 [1414 kB] 570s Get:35 http://ftpmaster.internal/ubuntu questing/main armhf libfwupd3 armhf 2.0.8-3 [126 kB] 570s Get:36 http://ftpmaster.internal/ubuntu questing/main armhf libmbim-proxy armhf 1.32.0-1 [5888 B] 570s Get:37 http://ftpmaster.internal/ubuntu questing/main armhf libmbim-glib4 armhf 1.32.0-1 [218 kB] 570s Get:38 http://ftpmaster.internal/ubuntu questing/main armhf libmm-glib0 armhf 1.24.0-1 [223 kB] 570s Get:39 http://ftpmaster.internal/ubuntu questing/main armhf libqmi-proxy armhf 1.36.0-1 [5882 B] 570s Get:40 http://ftpmaster.internal/ubuntu questing/main armhf libqmi-glib5 armhf 1.36.0-1 [936 kB] 570s Get:41 http://ftpmaster.internal/ubuntu questing/main armhf htop armhf 3.4.1-4 [147 kB] 570s Get:42 http://ftpmaster.internal/ubuntu questing/main armhf libftdi1-2 armhf 1.5-10 [27.8 kB] 570s Get:43 http://ftpmaster.internal/ubuntu questing/main armhf libnvme1t64 armhf 1.13-2 [74.3 kB] 570s Get:44 http://ftpmaster.internal/ubuntu questing/main armhf python3-lazr.restfulclient all 0.14.6-3 [51.0 kB] 570s Get:45 http://ftpmaster.internal/ubuntu questing/main armhf python3-more-itertools all 10.7.0-1 [59.6 kB] 570s Get:46 http://ftpmaster.internal/ubuntu questing/main armhf python3-s3transfer all 0.11.4-1 [55.8 kB] 570s Get:47 http://ftpmaster.internal/ubuntu questing/main armhf sos all 4.9.1-1 [367 kB] 570s Get:48 http://ftpmaster.internal/ubuntu questing/main armhf cloud-init all 25.2~1g7a0265d3-0ubuntu1 [2106 B] 570s Preconfiguring packages ... 571s Fetched 15.6 MB in 1s (11.9 MB/s) 571s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 571s Preparing to unpack .../motd-news-config_13.7ubuntu1_all.deb ... 571s Unpacking motd-news-config (13.7ubuntu1) over (13.6ubuntu2) ... 571s Preparing to unpack .../base-files_13.7ubuntu1_armhf.deb ... 571s Unpacking base-files (13.7ubuntu1) over (13.6ubuntu2) ... 571s Setting up base-files (13.7ubuntu1) ... 571s Installing new version of config file /etc/issue ... 571s Installing new version of config file /etc/issue.net ... 571s Installing new version of config file /etc/lsb-release ... 572s motd-news.service is a disabled or a static unit not running, not starting it. 572s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 572s Preparing to unpack .../debianutils_5.22_armhf.deb ... 572s Unpacking debianutils (5.22) over (5.21) ... 572s Setting up debianutils (5.22) ... 572s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 572s Preparing to unpack .../dpkg_1.22.18ubuntu3_armhf.deb ... 572s Unpacking dpkg (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 572s Setting up dpkg (1.22.18ubuntu3) ... 573s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 573s Preparing to unpack .../base-passwd_3.6.7_armhf.deb ... 573s Unpacking base-passwd (3.6.7) over (3.6.6) ... 573s Setting up base-passwd (3.6.7) ... 573s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 573s Preparing to unpack .../libsepol2_3.8.1-1_armhf.deb ... 573s Unpacking libsepol2:armhf (3.8.1-1) over (3.7-1) ... 573s Setting up libsepol2:armhf (3.8.1-1) ... 573s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 573s Preparing to unpack .../libnpth0t64_1.8-3_armhf.deb ... 573s Unpacking libnpth0t64:armhf (1.8-3) over (1.8-2) ... 573s Setting up libnpth0t64:armhf (1.8-3) ... 573s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63953 files and directories currently installed.) 573s Preparing to unpack .../00-distro-info-data_0.64_all.deb ... 573s Unpacking distro-info-data (0.64) over (0.63) ... 573s Preparing to unpack .../01-iso-codes_4.18.0-1_all.deb ... 573s Unpacking iso-codes (4.18.0-1) over (4.17.0-1) ... 574s Preparing to unpack .../02-libbpf1_1%3a1.5.0-3_armhf.deb ... 574s Unpacking libbpf1:armhf (1:1.5.0-3) over (1:1.5.0-2) ... 574s Preparing to unpack .../03-libsqlite3-0_3.46.1-4_armhf.deb ... 574s Unpacking libsqlite3-0:armhf (3.46.1-4) over (3.46.1-3) ... 574s Preparing to unpack .../04-libunistring5_1.3-2_armhf.deb ... 574s Unpacking libunistring5:armhf (1.3-2) over (1.3-1) ... 574s Preparing to unpack .../05-ubuntu-pro-client-l10n_35.1ubuntu0_armhf.deb ... 574s Unpacking ubuntu-pro-client-l10n (35.1ubuntu0) over (35) ... 574s Preparing to unpack .../06-ubuntu-pro-client_35.1ubuntu0_armhf.deb ... 574s Unpacking ubuntu-pro-client (35.1ubuntu0) over (35) ... 574s Preparing to unpack .../07-ed_1.21.1-1_armhf.deb ... 574s Unpacking ed (1.21.1-1) over (1.21-1) ... 574s Preparing to unpack .../08-ethtool_1%3a6.14-2_armhf.deb ... 574s Unpacking ethtool (1:6.14-2) over (1:6.11-1) ... 574s Preparing to unpack .../09-libevdev2_1.13.4+dfsg-1_armhf.deb ... 574s Unpacking libevdev2:armhf (1.13.4+dfsg-1) over (1.13.3+dfsg-1) ... 574s Preparing to unpack .../10-libnftnl11_1.2.9-1_armhf.deb ... 574s Unpacking libnftnl11:armhf (1.2.9-1) over (1.2.8-1) ... 574s Preparing to unpack .../11-libnghttp2-14_1.64.0-1.1_armhf.deb ... 574s Unpacking libnghttp2-14:armhf (1.64.0-1.1) over (1.64.0-1ubuntu1) ... 574s Preparing to unpack .../12-libsensors-config_1%3a3.6.2-2_all.deb ... 574s Unpacking libsensors-config (1:3.6.2-2) over (1:3.6.0-10) ... 574s Preparing to unpack .../13-libsensors5_1%3a3.6.2-2_armhf.deb ... 574s Unpacking libsensors5:armhf (1:3.6.2-2) over (1:3.6.0-10) ... 574s Preparing to unpack .../14-liburcu8t64_0.15.2-2_armhf.deb ... 574s Unpacking liburcu8t64:armhf (0.15.2-2) over (0.15.1-1) ... 574s Preparing to unpack .../15-libusb-1.0-0_2%3a1.0.28-1_armhf.deb ... 574s Unpacking libusb-1.0-0:armhf (2:1.0.28-1) over (2:1.0.27-2) ... 574s Preparing to unpack .../16-man-db_2.13.1-1_armhf.deb ... 574s Unpacking man-db (2.13.1-1) over (2.13.0-1) ... 575s Preparing to unpack .../17-nano_8.4-1_armhf.deb ... 575s Unpacking nano (8.4-1) over (8.3-1) ... 575s Preparing to unpack .../18-publicsuffix_20250328.1952-0.1_all.deb ... 575s Unpacking publicsuffix (20250328.1952-0.1) over (20250108.1153-0.1) ... 575s Preparing to unpack .../19-usb.ids_2025.04.01-1_all.deb ... 575s Unpacking usb.ids (2025.04.01-1) over (2025.01.14-1) ... 575s Preparing to unpack .../20-usbutils_1%3a018-2_armhf.deb ... 575s Unpacking usbutils (1:018-2) over (1:018-1) ... 575s Preparing to unpack .../21-cloud-init-base_25.2~1g7a0265d3-0ubuntu1_all.deb ... 575s Unpacking cloud-init-base (25.2~1g7a0265d3-0ubuntu1) over (25.1.1-0ubuntu2) ... 576s Preparing to unpack .../22-dpkg-dev_1.22.18ubuntu3_all.deb ... 576s Unpacking dpkg-dev (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 576s Preparing to unpack .../23-libdpkg-perl_1.22.18ubuntu3_all.deb ... 576s Unpacking libdpkg-perl (1.22.18ubuntu3) over (1.22.18ubuntu2) ... 576s Preparing to unpack .../24-patch_2.8-1_armhf.deb ... 576s Unpacking patch (2.8-1) over (2.7.6-7build3) ... 576s Preparing to unpack .../25-libjcat1_0.2.3-1_armhf.deb ... 576s Unpacking libjcat1:armhf (0.2.3-1) over (0.2.0-2build3) ... 576s Preparing to unpack .../26-fwupd_2.0.8-3_armhf.deb ... 576s Unpacking fwupd (2.0.8-3) over (2.0.7-1) ... 576s dpkg: warning: unable to delete old directory '/etc/grub.d': Directory not empty 576s Preparing to unpack .../27-libfwupd3_2.0.8-3_armhf.deb ... 576s Unpacking libfwupd3:armhf (2.0.8-3) over (2.0.7-1) ... 576s Preparing to unpack .../28-libmbim-proxy_1.32.0-1_armhf.deb ... 576s Unpacking libmbim-proxy (1.32.0-1) over (1.31.2-0ubuntu4) ... 576s Preparing to unpack .../29-libmbim-glib4_1.32.0-1_armhf.deb ... 576s Unpacking libmbim-glib4:armhf (1.32.0-1) over (1.31.2-0ubuntu4) ... 576s Preparing to unpack .../30-libmm-glib0_1.24.0-1_armhf.deb ... 576s Unpacking libmm-glib0:armhf (1.24.0-1) over (1.23.4-0ubuntu3) ... 576s Preparing to unpack .../31-libqmi-proxy_1.36.0-1_armhf.deb ... 576s Unpacking libqmi-proxy (1.36.0-1) over (1.35.6-1) ... 577s Preparing to unpack .../32-libqmi-glib5_1.36.0-1_armhf.deb ... 577s Unpacking libqmi-glib5:armhf (1.36.0-1) over (1.35.6-1) ... 577s Preparing to unpack .../33-htop_3.4.1-4_armhf.deb ... 577s Unpacking htop (3.4.1-4) over (3.4.0-2) ... 577s Preparing to unpack .../34-libftdi1-2_1.5-10_armhf.deb ... 577s Unpacking libftdi1-2:armhf (1.5-10) over (1.5-8build1) ... 577s Preparing to unpack .../35-libnvme1t64_1.13-2_armhf.deb ... 577s Unpacking libnvme1t64 (1.13-2) over (1.11.1-2) ... 577s Preparing to unpack .../36-python3-lazr.restfulclient_0.14.6-3_all.deb ... 577s Unpacking python3-lazr.restfulclient (0.14.6-3) over (0.14.6-2) ... 577s Preparing to unpack .../37-python3-more-itertools_10.7.0-1_all.deb ... 577s Unpacking python3-more-itertools (10.7.0-1) over (10.6.0-1) ... 577s Preparing to unpack .../38-python3-s3transfer_0.11.4-1_all.deb ... 577s Unpacking python3-s3transfer (0.11.4-1) over (0.11.2-2) ... 577s Preparing to unpack .../39-sos_4.9.1-1_all.deb ... 578s Unpacking sos (4.9.1-1) over (4.9.0-6) ... 578s Preparing to unpack .../40-cloud-init_25.2~1g7a0265d3-0ubuntu1_all.deb ... 578s Unpacking cloud-init (25.2~1g7a0265d3-0ubuntu1) over (25.1.1-0ubuntu2) ... 578s Setting up sos (4.9.1-1) ... 578s Setting up motd-news-config (13.7ubuntu1) ... 578s Setting up python3-more-itertools (10.7.0-1) ... 579s Setting up liburcu8t64:armhf (0.15.2-2) ... 579s Setting up distro-info-data (0.64) ... 579s Setting up htop (3.4.1-4) ... 579s Setting up libsqlite3-0:armhf (3.46.1-4) ... 579s Setting up python3-s3transfer (0.11.4-1) ... 579s Setting up libsensors-config (1:3.6.2-2) ... 579s Installing new version of config file /etc/sensors3.conf ... 579s Setting up libnghttp2-14:armhf (1.64.0-1.1) ... 579s Setting up libnftnl11:armhf (1.2.9-1) ... 579s Setting up man-db (2.13.1-1) ... 579s Updating database of manual pages ... 581s apparmor_parser: Unable to replace "/usr/bin/man". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 581s 581s man-db.service is a disabled or a static unit not running, not starting it. 581s Setting up cloud-init-base (25.2~1g7a0265d3-0ubuntu1) ... 583s Setting up libjcat1:armhf (0.2.3-1) ... 583s Setting up libnvme1t64 (1.13-2) ... 583s Setting up ed (1.21.1-1) ... 583s Setting up libunistring5:armhf (1.3-2) ... 583s Setting up patch (2.8-1) ... 583s Setting up usb.ids (2025.04.01-1) ... 583s Setting up libsensors5:armhf (1:3.6.2-2) ... 583s Setting up libdpkg-perl (1.22.18ubuntu3) ... 583s Setting up nano (8.4-1) ... 583s Installing new version of config file /etc/nanorc ... 583s Setting up libmm-glib0:armhf (1.24.0-1) ... 583s Setting up libusb-1.0-0:armhf (2:1.0.28-1) ... 583s Setting up python3-lazr.restfulclient (0.14.6-3) ... 583s Setting up libevdev2:armhf (1.13.4+dfsg-1) ... 583s Setting up publicsuffix (20250328.1952-0.1) ... 583s Setting up ubuntu-pro-client (35.1ubuntu0) ... 584s apparmor_parser: Unable to replace "ubuntu_pro_apt_news". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 584s 584s apparmor_parser: Unable to replace "apt_methods". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 584s 584s apparmor_parser: Unable to replace "ubuntu_pro_esm_cache". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 584s 585s Setting up iso-codes (4.18.0-1) ... 585s Setting up libbpf1:armhf (1:1.5.0-3) ... 585s Setting up libmbim-glib4:armhf (1.32.0-1) ... 585s Setting up ethtool (1:6.14-2) ... 585s Setting up ubuntu-pro-client-l10n (35.1ubuntu0) ... 585s Setting up cloud-init (25.2~1g7a0265d3-0ubuntu1) ... 585s Setting up libfwupd3:armhf (2.0.8-3) ... 585s Setting up libmbim-proxy (1.32.0-1) ... 585s Setting up usbutils (1:018-2) ... 585s Setting up dpkg-dev (1.22.18ubuntu3) ... 585s Setting up libftdi1-2:armhf (1.5-10) ... 585s Setting up libqmi-glib5:armhf (1.36.0-1) ... 585s Setting up libqmi-proxy (1.36.0-1) ... 585s Setting up fwupd (2.0.8-3) ... 586s fwupd-refresh.service is a disabled or a static unit not running, not starting it. 586s fwupd.service is a disabled or a static unit not running, not starting it. 586s Processing triggers for rsyslog (8.2412.0-2ubuntu2) ... 587s Processing triggers for plymouth-theme-ubuntu-text (24.004.60-2ubuntu7) ... 587s Processing triggers for dbus (1.16.2-2ubuntu1) ... 587s Processing triggers for install-info (7.1.1-1) ... 588s Processing triggers for libc-bin (2.41-6ubuntu1) ... 588s Processing triggers for initramfs-tools (0.147ubuntu1) ... 590s Reading package lists... 590s Building dependency tree... 590s Reading state information... 591s Starting pkgProblemResolver with broken count: 0 591s Starting 2 pkgProblemResolver with broken count: 0 591s Done 592s Solving dependencies... 593s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 595s autopkgtest [20:44:15]: rebooting testbed after setup commands that affected boot 659s Reading package lists... 659s Building dependency tree... 659s Reading state information... 660s Starting pkgProblemResolver with broken count: 0 660s Starting 2 pkgProblemResolver with broken count: 0 660s Done 661s The following NEW packages will be installed: 661s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 661s asterisk-modules freetds-common libasound2-data libasound2t64 libb64-0d 661s libc-client2007e libcodec2-1.2 libdeflate0 libevent-2.1-7t64 661s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libjbig0 661s libjpeg-turbo8 libjpeg8 libjwt2 liblerc4 libltdl7 liblua5.1-0 libneon27t64 661s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 661s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 661s libsharpyuv0 libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 661s libsrtp2-1 libsybdb5 libtiff6 libunbound8 liburiparser1 libvo-amrwbenc0 661s libvorbis0a libvorbisenc2 libvorbisfile3 libwebp7 libxslt1.1 mlock 661s 0 upgraded, 56 newly installed, 0 to remove and 0 not upgraded. 661s Need to get 26.7 MB of archives. 661s After this operation, 75.7 MB of additional disk space will be used. 661s Get:1 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-config all 1:22.2.0~dfsg+~cs6.15.60671435-2 [226 kB] 662s Get:2 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 662s Get:3 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 662s Get:4 http://ftpmaster.internal/ubuntu questing/universe armhf mlock armhf 8:2007f~dfsg-7.1 [8214 B] 662s Get:5 http://ftpmaster.internal/ubuntu questing/universe armhf libc-client2007e armhf 8:2007f~dfsg-7.1 [604 kB] 662s Get:6 http://ftpmaster.internal/ubuntu questing/universe armhf libcodec2-1.2 armhf 1.2.0-3 [8250 kB] 662s Get:7 http://ftpmaster.internal/ubuntu questing/universe armhf libgmime-3.0-0t64 armhf 3.2.15+dfsg-1 [149 kB] 662s Get:8 http://ftpmaster.internal/ubuntu questing/universe armhf libgsm1 armhf 1.0.22-1build1 [24.8 kB] 662s Get:9 http://ftpmaster.internal/ubuntu questing/main armhf libical3t64 armhf 3.0.20-1 [269 kB] 662s Get:10 http://ftpmaster.internal/ubuntu questing/universe armhf libiksemel3 armhf 1.4-4build2 [21.8 kB] 662s Get:11 http://ftpmaster.internal/ubuntu questing/main armhf libopus0 armhf 1.5.2-2 [2875 kB] 662s Get:12 http://ftpmaster.internal/ubuntu questing/main armhf libsamplerate0 armhf 0.2.2-4build1 [1341 kB] 662s Get:13 http://ftpmaster.internal/ubuntu questing/main armhf libjack-jackd2-0 armhf 1.9.22~dfsg-4 [247 kB] 662s Get:14 http://ftpmaster.internal/ubuntu questing/universe armhf libb64-0d armhf 1.2-5build1 [9166 B] 662s Get:15 http://ftpmaster.internal/ubuntu questing/universe armhf libjwt2 armhf 1.17.2-1 [14.7 kB] 662s Get:16 http://ftpmaster.internal/ubuntu questing/universe armhf liblua5.1-0 armhf 5.1.5-11 [91.3 kB] 662s Get:17 http://ftpmaster.internal/ubuntu questing/universe armhf libneon27t64 armhf 0.34.2-1 [91.5 kB] 662s Get:18 http://ftpmaster.internal/ubuntu questing/main armhf libltdl7 armhf 2.5.4-4 [39.8 kB] 662s Get:19 http://ftpmaster.internal/ubuntu questing/main armhf libodbc2 armhf 2.3.12-2ubuntu1 [145 kB] 662s Get:20 http://ftpmaster.internal/ubuntu questing/main armhf libogg0 armhf 1.3.5-3build1 [20.5 kB] 662s Get:21 http://ftpmaster.internal/ubuntu questing/universe armhf libopencore-amrnb0 armhf 0.1.6-1build1 [89.1 kB] 662s Get:22 http://ftpmaster.internal/ubuntu questing/universe armhf libopencore-amrwb0 armhf 0.1.6-1build1 [48.1 kB] 662s Get:23 http://ftpmaster.internal/ubuntu questing/universe armhf libopusenc0 armhf 0.2.1-2build1 [23.8 kB] 662s Get:24 http://ftpmaster.internal/ubuntu questing/universe armhf libopusfile0 armhf 0.12-4build3 [40.6 kB] 662s Get:25 http://ftpmaster.internal/ubuntu questing/main armhf libasound2-data all 1.2.13-1build1 [21.1 kB] 662s Get:26 http://ftpmaster.internal/ubuntu questing/main armhf libasound2t64 armhf 1.2.13-1build1 [347 kB] 662s Get:27 http://ftpmaster.internal/ubuntu questing/universe armhf libportaudio2 armhf 19.6.0-1.2build3 [60.9 kB] 662s Get:28 http://ftpmaster.internal/ubuntu questing/main armhf libpq5 armhf 17.4-1 [125 kB] 662s Get:29 http://ftpmaster.internal/ubuntu questing/universe armhf libradcli4 armhf 1.2.11-1build3 [37.5 kB] 662s Get:30 http://ftpmaster.internal/ubuntu questing/universe armhf libresample1 armhf 0.1.3-8 [7682 B] 662s Get:31 http://ftpmaster.internal/ubuntu questing/main armhf libsnmp-base all 5.9.4+dfsg-1.1ubuntu7 [206 kB] 662s Get:32 http://ftpmaster.internal/ubuntu questing/main armhf libsnmp40t64 armhf 5.9.4+dfsg-1.1ubuntu7 [1011 kB] 662s Get:33 http://ftpmaster.internal/ubuntu questing/main armhf libdeflate0 armhf 1.23-2 [38.7 kB] 662s Get:34 http://ftpmaster.internal/ubuntu questing/main armhf libjbig0 armhf 2.1-6.1ubuntu2 [24.9 kB] 662s Get:35 http://ftpmaster.internal/ubuntu questing/main armhf libjpeg-turbo8 armhf 2.1.5-3ubuntu2 [127 kB] 662s Get:36 http://ftpmaster.internal/ubuntu questing/main armhf libjpeg8 armhf 8c-2ubuntu11 [2148 B] 662s Get:37 http://ftpmaster.internal/ubuntu questing/main armhf liblerc4 armhf 4.0.0+ds-5ubuntu1 [160 kB] 662s Get:38 http://ftpmaster.internal/ubuntu questing/main armhf libsharpyuv0 armhf 1.5.0-0.1 [16.4 kB] 662s Get:39 http://ftpmaster.internal/ubuntu questing/main armhf libwebp7 armhf 1.5.0-0.1 [188 kB] 662s Get:40 http://ftpmaster.internal/ubuntu questing/main armhf libtiff6 armhf 4.7.0-3ubuntu1 [184 kB] 663s Get:41 http://ftpmaster.internal/ubuntu questing/universe armhf libspandsp2t64 armhf 0.0.6+dfsg-2.2 [268 kB] 663s Get:42 http://ftpmaster.internal/ubuntu questing/main armhf libspeex1 armhf 1.2.1-3 [49.0 kB] 663s Get:43 http://ftpmaster.internal/ubuntu questing/main armhf libspeexdsp1 armhf 1.2.1-3 [37.2 kB] 663s Get:44 http://ftpmaster.internal/ubuntu questing/universe armhf libsrtp2-1 armhf 2.7.0-3 [35.3 kB] 663s Get:45 http://ftpmaster.internal/ubuntu questing/main armhf freetds-common all 1.3.17+ds-2build3 [26.9 kB] 663s Get:46 http://ftpmaster.internal/ubuntu questing/main armhf libsybdb5 armhf 1.3.17+ds-2build3 [179 kB] 663s Get:47 http://ftpmaster.internal/ubuntu questing/main armhf libevent-2.1-7t64 armhf 2.1.12-stable-10 [127 kB] 663s Get:48 http://ftpmaster.internal/ubuntu questing/main armhf libunbound8 armhf 1.22.0-1ubuntu1 [423 kB] 663s Get:49 http://ftpmaster.internal/ubuntu questing/universe armhf libvo-amrwbenc0 armhf 0.1.3-2build1 [67.2 kB] 663s Get:50 http://ftpmaster.internal/ubuntu questing/main armhf libvorbis0a armhf 1.3.7-2 [86.7 kB] 663s Get:51 http://ftpmaster.internal/ubuntu questing/main armhf libvorbisenc2 armhf 1.3.7-2 [72.9 kB] 663s Get:52 http://ftpmaster.internal/ubuntu questing/main armhf libvorbisfile3 armhf 1.3.7-2 [16.2 kB] 663s Get:53 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk-modules armhf 1:22.2.0~dfsg+~cs6.15.60671435-2 [3021 kB] 663s Get:54 http://ftpmaster.internal/ubuntu questing/universe armhf liburiparser1 armhf 0.9.8+dfsg-2 [30.3 kB] 663s Get:55 http://ftpmaster.internal/ubuntu questing/main armhf libxslt1.1 armhf 1.1.39-0exp1ubuntu4 [151 kB] 663s Get:56 http://ftpmaster.internal/ubuntu questing/universe armhf asterisk armhf 1:22.2.0~dfsg+~cs6.15.60671435-2 [2454 kB] 663s Fetched 26.7 MB in 2s (15.3 MB/s) 663s Selecting previously unselected package asterisk-config. 664s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 63964 files and directories currently installed.) 664s Preparing to unpack .../00-asterisk-config_1%3a22.2.0~dfsg+~cs6.15.60671435-2_all.deb ... 664s Unpacking asterisk-config (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 664s Selecting previously unselected package asterisk-core-sounds-en-gsm. 664s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 664s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 664s Selecting previously unselected package asterisk-core-sounds-en. 664s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 664s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 664s Selecting previously unselected package mlock. 664s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7.1_armhf.deb ... 664s Unpacking mlock (8:2007f~dfsg-7.1) ... 664s Selecting previously unselected package libc-client2007e. 664s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7.1_armhf.deb ... 664s Unpacking libc-client2007e (8:2007f~dfsg-7.1) ... 664s Selecting previously unselected package libcodec2-1.2:armhf. 664s Preparing to unpack .../05-libcodec2-1.2_1.2.0-3_armhf.deb ... 664s Unpacking libcodec2-1.2:armhf (1.2.0-3) ... 664s Selecting previously unselected package libgmime-3.0-0t64:armhf. 664s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.15+dfsg-1_armhf.deb ... 664s Unpacking libgmime-3.0-0t64:armhf (3.2.15+dfsg-1) ... 664s Selecting previously unselected package libgsm1:armhf. 664s Preparing to unpack .../07-libgsm1_1.0.22-1build1_armhf.deb ... 664s Unpacking libgsm1:armhf (1.0.22-1build1) ... 664s Selecting previously unselected package libical3t64:armhf. 664s Preparing to unpack .../08-libical3t64_3.0.20-1_armhf.deb ... 664s Unpacking libical3t64:armhf (3.0.20-1) ... 664s Selecting previously unselected package libiksemel3:armhf. 664s Preparing to unpack .../09-libiksemel3_1.4-4build2_armhf.deb ... 664s Unpacking libiksemel3:armhf (1.4-4build2) ... 664s Selecting previously unselected package libopus0:armhf. 664s Preparing to unpack .../10-libopus0_1.5.2-2_armhf.deb ... 664s Unpacking libopus0:armhf (1.5.2-2) ... 664s Selecting previously unselected package libsamplerate0:armhf. 664s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_armhf.deb ... 664s Unpacking libsamplerate0:armhf (0.2.2-4build1) ... 664s Selecting previously unselected package libjack-jackd2-0:armhf. 664s Preparing to unpack .../12-libjack-jackd2-0_1.9.22~dfsg-4_armhf.deb ... 664s Unpacking libjack-jackd2-0:armhf (1.9.22~dfsg-4) ... 664s Selecting previously unselected package libb64-0d:armhf. 664s Preparing to unpack .../13-libb64-0d_1.2-5build1_armhf.deb ... 664s Unpacking libb64-0d:armhf (1.2-5build1) ... 664s Selecting previously unselected package libjwt2:armhf. 664s Preparing to unpack .../14-libjwt2_1.17.2-1_armhf.deb ... 664s Unpacking libjwt2:armhf (1.17.2-1) ... 664s Selecting previously unselected package liblua5.1-0:armhf. 664s Preparing to unpack .../15-liblua5.1-0_5.1.5-11_armhf.deb ... 664s Unpacking liblua5.1-0:armhf (5.1.5-11) ... 664s Selecting previously unselected package libneon27t64:armhf. 664s Preparing to unpack .../16-libneon27t64_0.34.2-1_armhf.deb ... 664s Unpacking libneon27t64:armhf (0.34.2-1) ... 664s Selecting previously unselected package libltdl7:armhf. 665s Preparing to unpack .../17-libltdl7_2.5.4-4_armhf.deb ... 665s Unpacking libltdl7:armhf (2.5.4-4) ... 665s Selecting previously unselected package libodbc2:armhf. 665s Preparing to unpack .../18-libodbc2_2.3.12-2ubuntu1_armhf.deb ... 665s Unpacking libodbc2:armhf (2.3.12-2ubuntu1) ... 665s Selecting previously unselected package libogg0:armhf. 665s Preparing to unpack .../19-libogg0_1.3.5-3build1_armhf.deb ... 665s Unpacking libogg0:armhf (1.3.5-3build1) ... 665s Selecting previously unselected package libopencore-amrnb0:armhf. 665s Preparing to unpack .../20-libopencore-amrnb0_0.1.6-1build1_armhf.deb ... 665s Unpacking libopencore-amrnb0:armhf (0.1.6-1build1) ... 665s Selecting previously unselected package libopencore-amrwb0:armhf. 665s Preparing to unpack .../21-libopencore-amrwb0_0.1.6-1build1_armhf.deb ... 665s Unpacking libopencore-amrwb0:armhf (0.1.6-1build1) ... 665s Selecting previously unselected package libopusenc0:armhf. 665s Preparing to unpack .../22-libopusenc0_0.2.1-2build1_armhf.deb ... 665s Unpacking libopusenc0:armhf (0.2.1-2build1) ... 665s Selecting previously unselected package libopusfile0:armhf. 665s Preparing to unpack .../23-libopusfile0_0.12-4build3_armhf.deb ... 665s Unpacking libopusfile0:armhf (0.12-4build3) ... 665s Selecting previously unselected package libasound2-data. 665s Preparing to unpack .../24-libasound2-data_1.2.13-1build1_all.deb ... 665s Unpacking libasound2-data (1.2.13-1build1) ... 665s Selecting previously unselected package libasound2t64:armhf. 665s Preparing to unpack .../25-libasound2t64_1.2.13-1build1_armhf.deb ... 665s Unpacking libasound2t64:armhf (1.2.13-1build1) ... 665s Selecting previously unselected package libportaudio2:armhf. 665s Preparing to unpack .../26-libportaudio2_19.6.0-1.2build3_armhf.deb ... 665s Unpacking libportaudio2:armhf (19.6.0-1.2build3) ... 665s Selecting previously unselected package libpq5:armhf. 665s Preparing to unpack .../27-libpq5_17.4-1_armhf.deb ... 665s Unpacking libpq5:armhf (17.4-1) ... 665s Selecting previously unselected package libradcli4. 665s Preparing to unpack .../28-libradcli4_1.2.11-1build3_armhf.deb ... 665s Unpacking libradcli4 (1.2.11-1build3) ... 665s Selecting previously unselected package libresample1. 665s Preparing to unpack .../29-libresample1_0.1.3-8_armhf.deb ... 665s Unpacking libresample1 (0.1.3-8) ... 665s Selecting previously unselected package libsnmp-base. 665s Preparing to unpack .../30-libsnmp-base_5.9.4+dfsg-1.1ubuntu7_all.deb ... 665s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu7) ... 665s Selecting previously unselected package libsnmp40t64:armhf. 665s Preparing to unpack .../31-libsnmp40t64_5.9.4+dfsg-1.1ubuntu7_armhf.deb ... 665s Unpacking libsnmp40t64:armhf (5.9.4+dfsg-1.1ubuntu7) ... 665s Selecting previously unselected package libdeflate0:armhf. 665s Preparing to unpack .../32-libdeflate0_1.23-2_armhf.deb ... 665s Unpacking libdeflate0:armhf (1.23-2) ... 665s Selecting previously unselected package libjbig0:armhf. 665s Preparing to unpack .../33-libjbig0_2.1-6.1ubuntu2_armhf.deb ... 665s Unpacking libjbig0:armhf (2.1-6.1ubuntu2) ... 665s Selecting previously unselected package libjpeg-turbo8:armhf. 665s Preparing to unpack .../34-libjpeg-turbo8_2.1.5-3ubuntu2_armhf.deb ... 665s Unpacking libjpeg-turbo8:armhf (2.1.5-3ubuntu2) ... 665s Selecting previously unselected package libjpeg8:armhf. 665s Preparing to unpack .../35-libjpeg8_8c-2ubuntu11_armhf.deb ... 665s Unpacking libjpeg8:armhf (8c-2ubuntu11) ... 665s Selecting previously unselected package liblerc4:armhf. 665s Preparing to unpack .../36-liblerc4_4.0.0+ds-5ubuntu1_armhf.deb ... 665s Unpacking liblerc4:armhf (4.0.0+ds-5ubuntu1) ... 665s Selecting previously unselected package libsharpyuv0:armhf. 665s Preparing to unpack .../37-libsharpyuv0_1.5.0-0.1_armhf.deb ... 665s Unpacking libsharpyuv0:armhf (1.5.0-0.1) ... 665s Selecting previously unselected package libwebp7:armhf. 665s Preparing to unpack .../38-libwebp7_1.5.0-0.1_armhf.deb ... 665s Unpacking libwebp7:armhf (1.5.0-0.1) ... 665s Selecting previously unselected package libtiff6:armhf. 665s Preparing to unpack .../39-libtiff6_4.7.0-3ubuntu1_armhf.deb ... 665s Unpacking libtiff6:armhf (4.7.0-3ubuntu1) ... 666s Selecting previously unselected package libspandsp2t64:armhf. 666s Preparing to unpack .../40-libspandsp2t64_0.0.6+dfsg-2.2_armhf.deb ... 666s Unpacking libspandsp2t64:armhf (0.0.6+dfsg-2.2) ... 666s Selecting previously unselected package libspeex1:armhf. 666s Preparing to unpack .../41-libspeex1_1.2.1-3_armhf.deb ... 666s Unpacking libspeex1:armhf (1.2.1-3) ... 666s Selecting previously unselected package libspeexdsp1:armhf. 666s Preparing to unpack .../42-libspeexdsp1_1.2.1-3_armhf.deb ... 666s Unpacking libspeexdsp1:armhf (1.2.1-3) ... 666s Selecting previously unselected package libsrtp2-1:armhf. 666s Preparing to unpack .../43-libsrtp2-1_2.7.0-3_armhf.deb ... 666s Unpacking libsrtp2-1:armhf (2.7.0-3) ... 666s Selecting previously unselected package freetds-common. 666s Preparing to unpack .../44-freetds-common_1.3.17+ds-2build3_all.deb ... 666s Unpacking freetds-common (1.3.17+ds-2build3) ... 666s Selecting previously unselected package libsybdb5:armhf. 666s Preparing to unpack .../45-libsybdb5_1.3.17+ds-2build3_armhf.deb ... 666s Unpacking libsybdb5:armhf (1.3.17+ds-2build3) ... 666s Selecting previously unselected package libevent-2.1-7t64:armhf. 666s Preparing to unpack .../46-libevent-2.1-7t64_2.1.12-stable-10_armhf.deb ... 666s Unpacking libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 666s Selecting previously unselected package libunbound8:armhf. 666s Preparing to unpack .../47-libunbound8_1.22.0-1ubuntu1_armhf.deb ... 666s Unpacking libunbound8:armhf (1.22.0-1ubuntu1) ... 666s Selecting previously unselected package libvo-amrwbenc0:armhf. 666s Preparing to unpack .../48-libvo-amrwbenc0_0.1.3-2build1_armhf.deb ... 666s Unpacking libvo-amrwbenc0:armhf (0.1.3-2build1) ... 666s Selecting previously unselected package libvorbis0a:armhf. 666s Preparing to unpack .../49-libvorbis0a_1.3.7-2_armhf.deb ... 666s Unpacking libvorbis0a:armhf (1.3.7-2) ... 666s Selecting previously unselected package libvorbisenc2:armhf. 666s Preparing to unpack .../50-libvorbisenc2_1.3.7-2_armhf.deb ... 666s Unpacking libvorbisenc2:armhf (1.3.7-2) ... 666s Selecting previously unselected package libvorbisfile3:armhf. 666s Preparing to unpack .../51-libvorbisfile3_1.3.7-2_armhf.deb ... 666s Unpacking libvorbisfile3:armhf (1.3.7-2) ... 666s Selecting previously unselected package asterisk-modules. 666s Preparing to unpack .../52-asterisk-modules_1%3a22.2.0~dfsg+~cs6.15.60671435-2_armhf.deb ... 666s Unpacking asterisk-modules (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 666s Selecting previously unselected package liburiparser1:armhf. 666s Preparing to unpack .../53-liburiparser1_0.9.8+dfsg-2_armhf.deb ... 666s Unpacking liburiparser1:armhf (0.9.8+dfsg-2) ... 666s Selecting previously unselected package libxslt1.1:armhf. 666s Preparing to unpack .../54-libxslt1.1_1.1.39-0exp1ubuntu4_armhf.deb ... 666s Unpacking libxslt1.1:armhf (1.1.39-0exp1ubuntu4) ... 666s Selecting previously unselected package asterisk. 666s Preparing to unpack .../55-asterisk_1%3a22.2.0~dfsg+~cs6.15.60671435-2_armhf.deb ... 666s Unpacking asterisk (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 667s Setting up libsharpyuv0:armhf (1.5.0-0.1) ... 667s Setting up libvo-amrwbenc0:armhf (0.1.3-2build1) ... 667s Setting up libneon27t64:armhf (0.34.2-1) ... 667s Setting up libogg0:armhf (1.3.5-3build1) ... 667s Setting up liblerc4:armhf (4.0.0+ds-5ubuntu1) ... 667s Setting up libspeex1:armhf (1.2.1-3) ... 667s Setting up libgsm1:armhf (1.0.22-1build1) ... 667s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 667s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu7) ... 667s Setting up libcodec2-1.2:armhf (1.2.0-3) ... 667s Setting up mlock (8:2007f~dfsg-7.1) ... 667s Setting up libsrtp2-1:armhf (2.7.0-3) ... 667s Setting up libpq5:armhf (17.4-1) ... 667s Setting up libdeflate0:armhf (1.23-2) ... 667s Setting up libevent-2.1-7t64:armhf (2.1.12-stable-10) ... 667s Setting up libb64-0d:armhf (1.2-5build1) ... 667s Setting up libjwt2:armhf (1.17.2-1) ... 667s Setting up libjbig0:armhf (2.1-6.1ubuntu2) ... 667s Setting up libasound2-data (1.2.13-1build1) ... 667s Setting up libopencore-amrwb0:armhf (0.1.6-1build1) ... 667s Setting up libunbound8:armhf (1.22.0-1ubuntu1) ... 667s Setting up libasound2t64:armhf (1.2.13-1build1) ... 667s Setting up libradcli4 (1.2.11-1build3) ... 667s Setting up libopus0:armhf (1.5.2-2) ... 667s Setting up asterisk-config (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 667s Setting up libvorbis0a:armhf (1.3.7-2) ... 667s Setting up libical3t64:armhf (3.0.20-1) ... 667s Setting up libjpeg-turbo8:armhf (2.1.5-3ubuntu2) ... 667s Setting up libltdl7:armhf (2.5.4-4) ... 667s Setting up asterisk-core-sounds-en (1.6.1-1) ... 667s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 667s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en_US (asterisk-prompt-en-us) in auto mode 667s Setting up libwebp7:armhf (1.5.0-0.1) ... 667s Setting up libiksemel3:armhf (1.4-4build2) ... 667s Setting up libodbc2:armhf (2.3.12-2ubuntu1) ... 667s Setting up liburiparser1:armhf (0.9.8+dfsg-2) ... 667s Setting up libspeexdsp1:armhf (1.2.1-3) ... 667s Setting up liblua5.1-0:armhf (5.1.5-11) ... 667s Setting up libxslt1.1:armhf (1.1.39-0exp1ubuntu4) ... 667s Setting up libopencore-amrnb0:armhf (0.1.6-1build1) ... 667s Setting up libc-client2007e (8:2007f~dfsg-7.1) ... 667s Setting up libresample1 (0.1.3-8) ... 667s Setting up freetds-common (1.3.17+ds-2build3) ... 667s Setting up libgmime-3.0-0t64:armhf (3.2.15+dfsg-1) ... 667s Setting up libsamplerate0:armhf (0.2.2-4build1) ... 667s Setting up libopusfile0:armhf (0.12-4build3) ... 667s Setting up libvorbisenc2:armhf (1.3.7-2) ... 667s Setting up libjpeg8:armhf (8c-2ubuntu11) ... 667s Setting up libopusenc0:armhf (0.2.1-2build1) ... 667s Setting up libsnmp40t64:armhf (5.9.4+dfsg-1.1ubuntu7) ... 667s Setting up libsybdb5:armhf (1.3.17+ds-2build3) ... 667s Setting up libvorbisfile3:armhf (1.3.7-2) ... 667s Setting up libjack-jackd2-0:armhf (1.9.22~dfsg-4) ... 667s Setting up libtiff6:armhf (4.7.0-3ubuntu1) ... 667s Setting up libportaudio2:armhf (19.6.0-1.2build3) ... 667s Setting up libspandsp2t64:armhf (0.0.6+dfsg-2.2) ... 667s Setting up asterisk-modules (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 667s Setting up asterisk (1:22.2.0~dfsg+~cs6.15.60671435-2) ... 667s Adding system user for Asterisk 667s info: Adding user `asterisk' to group `dialout' ... 667s info: Adding user `asterisk' to group `audio' ... 668s Created symlink '/etc/systemd/system/multi-user.target.wants/asterisk.service' → '/usr/lib/systemd/system/asterisk.service'. 670s Processing triggers for man-db (2.13.1-1) ... 670s Processing triggers for libc-bin (2.41-6ubuntu1) ... 693s autopkgtest [20:45:53]: test amr: [----------------------- 696s 1 audio amr amr 0 (AMR) 696s 2 audio amrwb amrwb 0 (AMR-WB) 696s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 696s amr - 23000 15000 15000 15000 15000 15000 15000 15000 9000 17000 17000 17000 17000 17000 17000 17000 17000 15000 15000 23000 23000 17250 15000 696s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 696s amrwb 23500 - 23500 23500 23500 23500 23500 23500 23500 17500 17500 9000 17000 17000 17000 17000 17000 17000 23500 23500 15000 23000 15000 14999 696s autopkgtest [20:45:56]: test amr: -----------------------] 700s autopkgtest [20:46:00]: test amr: - - - - - - - - - - results - - - - - - - - - - 700s amr PASS 704s autopkgtest [20:46:04]: @@@@@@@@@@@@@@@@@@@@ summary 704s asttestmods PASS 704s amr PASS