0s autopkgtest [09:00:30]: starting date and time: 2025-01-14 09:00:30+0000 0s autopkgtest [09:00:30]: git checkout: 325255d2 Merge branch 'pin-any-arch' into 'ubuntu/production' 0s autopkgtest [09:00:30]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.u8unkfg5/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:util-linux,src:golang-github-containers-buildah,src:golang-github-containers-psgo,src:mmdebstrap,src:shadow,src:sssd --apt-upgrade asterisk --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=util-linux/2.40.2-14ubuntu1 golang-github-containers-buildah/1.38.0+ds1-2 golang-github-containers-psgo/1.9.0-1 mmdebstrap/1.5.6-2 shadow/1:4.16.0-7ubuntu1 sssd/2.10.1-1ubuntu2' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-ppc64el-1.secgroup --name adt-plucky-ppc64el-asterisk-20250114-082527-juju-7f2275-prod-proposed-migration-environment-2-8ac9f10b-f226-4a39-8843-7e04e560acaa --image adt/ubuntu-plucky-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-ppc64el -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 118s autopkgtest [09:02:28]: testbed dpkg architecture: ppc64el 118s autopkgtest [09:02:28]: testbed apt version: 2.9.18 119s autopkgtest [09:02:29]: @@@@@@@@@@@@@@@@@@@@ test bed setup 119s autopkgtest [09:02:29]: testbed release detected to be: None 120s autopkgtest [09:02:30]: updating testbed package index (apt update) 120s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 120s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 120s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 120s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 120s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [856 kB] 121s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [138 kB] 121s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [9708 B] 121s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [10.3 kB] 121s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el Packages [259 kB] 121s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/restricted ppc64el Packages [756 B] 121s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/universe ppc64el Packages [983 kB] 121s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse ppc64el Packages [4080 B] 121s Fetched 2334 kB in 1s (2122 kB/s) 122s Reading package lists... 122s + lsb_release --codename --short 122s + RELEASE=plucky 122s + cat 122s + [ plucky != trusty ] 122s + DEBIAN_FRONTEND=noninteractive eatmydata apt-get -y --allow-downgrades -o Dpkg::Options::=--force-confnew dist-upgrade 122s Reading package lists... 123s Building dependency tree... 123s Reading state information... 123s Calculating upgrade... 123s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 123s + rm /etc/apt/preferences.d/force-downgrade-to-release.pref 123s + /usr/lib/apt/apt-helper analyze-pattern ?true 123s + DEBIAN_FRONTEND=noninteractive eatmydata apt-get -y purge --autoremove ?obsoleteReading package lists... 123s Building dependency tree... 123s 123s Reading state information... 124s 0 upgraded, 0 newly installed, 0 to remove and 14 not upgraded. 124s + grep -q trusty /etc/lsb-release 124s + [ ! -d /usr/share/doc/unattended-upgrades ] 124s + [ ! -d /usr/share/doc/lxd ] 124s + [ ! -d /usr/share/doc/lxd-client ] 124s + [ ! -d /usr/share/doc/snapd ] 124s + type iptables 124s + cat 124s + chmod 755 /etc/rc.local 124s + . /etc/rc.local 124s + iptables -w -t mangle -A FORWARD -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu 124s + iptables -A OUTPUT -d 10.255.255.1/32 -p tcp -j DROP 124s + iptables -A OUTPUT -d 10.255.255.2/32 -p tcp -j DROP 124s + uname -m 124s + [ ppc64le = ppc64le ] 124s + systemctl is-active keyboard-setup.service 124s + [ active = failed ] 124s + [ -d /run/systemd/system ] 124s + systemd-detect-virt --quiet --vm 124s + mkdir -p /etc/systemd/system/systemd-random-seed.service.d/ 124s + cat 124s + grep -q lz4 /etc/initramfs-tools/initramfs.conf 124s + echo COMPRESS=lz4 124s autopkgtest [09:02:34]: upgrading testbed (apt dist-upgrade and autopurge) 124s Reading package lists... 124s Building dependency tree... 124s Reading state information... 124s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 124s Starting 2 pkgProblemResolver with broken count: 0 124s Done 125s Entering ResolveByKeep 125s 125s The following NEW packages will be installed: 125s login.defs 125s The following packages will be upgraded: 125s bsdextrautils bsdutils eject fdisk libblkid1 libfdisk1 libmount1 125s libsmartcols1 libuuid1 login mount passwd util-linux uuid-runtime 125s 14 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 125s Need to get 3680 kB of archives. 125s After this operation, 1376 kB of additional disk space will be used. 125s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el bsdutils ppc64el 1:2.40.2-14ubuntu1 [105 kB] 125s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el eject ppc64el 2.40.2-14ubuntu1 [47.8 kB] 125s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el bsdextrautils ppc64el 2.40.2-14ubuntu1 [92.9 kB] 125s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libfdisk1 ppc64el 2.40.2-14ubuntu1 [188 kB] 125s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el fdisk ppc64el 2.40.2-14ubuntu1 [153 kB] 126s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libblkid1 ppc64el 2.40.2-14ubuntu1 [161 kB] 126s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libmount1 ppc64el 2.40.2-14ubuntu1 [190 kB] 126s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libsmartcols1 ppc64el 2.40.2-14ubuntu1 [108 kB] 126s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el mount ppc64el 2.40.2-14ubuntu1 [146 kB] 126s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libuuid1 ppc64el 2.40.2-14ubuntu1 [45.3 kB] 126s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el util-linux ppc64el 2.40.2-14ubuntu1 [1176 kB] 126s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el uuid-runtime ppc64el 2.40.2-14ubuntu1 [54.6 kB] 126s Get:13 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el login.defs all 1:4.16.0-7ubuntu1 [38.5 kB] 126s Get:14 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el login ppc64el 1:4.16.0-2+really2.40.2-14ubuntu1 [78.7 kB] 126s Get:15 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el passwd ppc64el 1:4.16.0-7ubuntu1 [1094 kB] 126s Fetched 3680 kB in 1s (4777 kB/s) 126s (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 ... 74045 files and directories currently installed.) 126s Preparing to unpack .../bsdutils_1%3a2.40.2-14ubuntu1_ppc64el.deb ... 126s Unpacking bsdutils (1:2.40.2-14ubuntu1) over (1:2.40.2-1ubuntu2) ... 126s Setting up bsdutils (1:2.40.2-14ubuntu1) ... 126s (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 ... 74045 files and directories currently installed.) 126s Preparing to unpack .../eject_2.40.2-14ubuntu1_ppc64el.deb ... 126s Unpacking eject (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 126s Preparing to unpack .../bsdextrautils_2.40.2-14ubuntu1_ppc64el.deb ... 126s Unpacking bsdextrautils (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Preparing to unpack .../libfdisk1_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking libfdisk1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Preparing to unpack .../fdisk_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking fdisk (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Preparing to unpack .../libblkid1_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking libblkid1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Setting up libblkid1:ppc64el (2.40.2-14ubuntu1) ... 127s (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 ... 74041 files and directories currently installed.) 127s Preparing to unpack .../libmount1_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking libmount1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Setting up libmount1:ppc64el (2.40.2-14ubuntu1) ... 127s (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 ... 74041 files and directories currently installed.) 127s Preparing to unpack .../libsmartcols1_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking libsmartcols1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Setting up libsmartcols1:ppc64el (2.40.2-14ubuntu1) ... 127s (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 ... 74041 files and directories currently installed.) 127s Preparing to unpack .../mount_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking mount (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Preparing to unpack .../libuuid1_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking libuuid1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Setting up libuuid1:ppc64el (2.40.2-14ubuntu1) ... 127s (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 ... 74041 files and directories currently installed.) 127s Preparing to unpack .../util-linux_2.40.2-14ubuntu1_ppc64el.deb ... 127s Unpacking util-linux (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 127s Setting up util-linux (2.40.2-14ubuntu1) ... 128s fstrim.service is a disabled or a static unit not running, not starting it. 128s (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 ... 74034 files and directories currently installed.) 128s Preparing to unpack .../uuid-runtime_2.40.2-14ubuntu1_ppc64el.deb ... 128s Unpacking uuid-runtime (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 128s Selecting previously unselected package login.defs. 128s Preparing to unpack .../login.defs_1%3a4.16.0-7ubuntu1_all.deb ... 128s Unpacking login.defs (1:4.16.0-7ubuntu1) ... 128s Replacing files in old package login (1:4.15.3-3ubuntu2) ... 128s Setting up login.defs (1:4.16.0-7ubuntu1) ... 128s Installing new version of config file /etc/login.defs ... 128s (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 ... 74038 files and directories currently installed.) 128s Preparing to unpack .../login_1%3a4.16.0-2+really2.40.2-14ubuntu1_ppc64el.deb ... 128s Unpacking login (1:4.16.0-2+really2.40.2-14ubuntu1) over (1:4.15.3-3ubuntu2) ... 128s Preparing to unpack .../passwd_1%3a4.16.0-7ubuntu1_ppc64el.deb ... 128s Unpacking passwd (1:4.16.0-7ubuntu1) over (1:4.15.3-3ubuntu2) ... 128s Setting up passwd (1:4.16.0-7ubuntu1) ... 128s Setting up bsdextrautils (2.40.2-14ubuntu1) ... 128s Setting up eject (2.40.2-14ubuntu1) ... 128s Setting up libfdisk1:ppc64el (2.40.2-14ubuntu1) ... 128s Setting up mount (2.40.2-14ubuntu1) ... 128s Setting up uuid-runtime (2.40.2-14ubuntu1) ... 129s uuidd.service is a disabled or a static unit not running, not starting it. 129s Setting up login (1:4.16.0-2+really2.40.2-14ubuntu1) ... 129s Setting up fdisk (2.40.2-14ubuntu1) ... 129s Processing triggers for man-db (2.13.0-1) ... 131s Processing triggers for libc-bin (2.40-4ubuntu1) ... 132s Reading package lists... 132s Building dependency tree... 132s Reading state information... 132s Starting pkgProblemResolver with broken count: 0 132s Starting 2 pkgProblemResolver with broken count: 0 132s Done 133s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 133s autopkgtest [09:02:43]: rebooting testbed after setup commands that affected boot 167s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 173s autopkgtest [09:03:23]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP Mon Sep 16 13:49:23 UTC 2024 176s autopkgtest [09:03:26]: @@@@@@@@@@@@@@@@@@@@ apt-source asterisk 183s Get:1 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (dsc) [5416 B] 183s Get:2 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (tar) [11.3 kB] 183s Get:3 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (tar) [22.0 kB] 183s Get:4 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (tar) [22.5 kB] 183s Get:5 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (tar) [6344 kB] 183s Get:6 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (tar) [5938 kB] 183s Get:7 http://ftpmaster.internal/ubuntu plucky/universe asterisk 1:22.1.0~dfsg+~cs6.14.60671435-1 (diff) [122 kB] 184s gpgv: Signature made Wed Nov 27 11:44:19 2024 UTC 184s gpgv: using RSA key 9FE3E9C36691A69FF53CC6842C7C3146C1A00121 184s gpgv: Can't check signature: No public key 184s dpkg-source: warning: cannot verify inline signature for ./asterisk_22.1.0~dfsg+~cs6.14.60671435-1.dsc: no acceptable signature found 185s autopkgtest [09:03:35]: testing package asterisk version 1:22.1.0~dfsg+~cs6.14.60671435-1 186s autopkgtest [09:03:36]: build not needed 191s autopkgtest [09:03:41]: test asttestmods: preparing testbed 191s Reading package lists... 191s Building dependency tree... 191s Reading state information... 191s Starting pkgProblemResolver with broken count: 0 191s Starting 2 pkgProblemResolver with broken count: 0 191s Done 192s The following NEW packages will be installed: 192s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 192s asterisk-modules asterisk-tests freetds-common libasound2-data libasound2t64 192s libb64-0d libc-client2007e libcodec2-1.2 libdeflate0 libevent-2.1-7t64 192s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libjbig0 192s libjpeg-turbo8 libjpeg8 libjwt2 liblerc4 libltdl7 liblua5.1-0 libneon27t64 192s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 192s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 192s libsharpyuv0 libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 192s libsrtp2-1 libsybdb5 libtiff6 libunbound8 liburiparser1 libvo-amrwbenc0 192s libvorbis0a libvorbisenc2 libvorbisfile3 libwebp7 libxml2-utils libxslt1.1 192s mlock 192s 0 upgraded, 58 newly installed, 0 to remove and 0 not upgraded. 192s Need to get 30.9 MB of archives. 192s After this operation, 103 MB of additional disk space will be used. 192s Get:1 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-config all 1:22.1.0~dfsg+~cs6.14.60671435-1 [223 kB] 192s Get:2 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 193s Get:3 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 193s Get:4 http://ftpmaster.internal/ubuntu plucky/universe ppc64el mlock ppc64el 8:2007f~dfsg-7.1 [8576 B] 193s Get:5 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libc-client2007e ppc64el 8:2007f~dfsg-7.1 [676 kB] 193s Get:6 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libcodec2-1.2 ppc64el 1.2.0-2build1 [9048 kB] 193s Get:7 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libgmime-3.0-0t64 ppc64el 3.2.15+dfsg-1 [205 kB] 193s Get:8 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libgsm1 ppc64el 1.0.22-1build1 [41.9 kB] 193s Get:9 http://ftpmaster.internal/ubuntu plucky/main ppc64el libical3t64 ppc64el 3.0.19-1build1 [346 kB] 193s Get:10 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libiksemel3 ppc64el 1.4-4build2 [34.8 kB] 193s Get:11 http://ftpmaster.internal/ubuntu plucky/main ppc64el libopus0 ppc64el 1.5.2-2 [3038 kB] 193s Get:12 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsamplerate0 ppc64el 0.2.2-4build1 [1348 kB] 193s Get:13 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjack-jackd2-0 ppc64el 1.9.22~dfsg-4 [332 kB] 193s Get:14 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libb64-0d ppc64el 1.2-5build1 [9882 B] 193s Get:15 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libjwt2 ppc64el 1.17.2-1 [20.3 kB] 193s Get:16 http://ftpmaster.internal/ubuntu plucky/universe ppc64el liblua5.1-0 ppc64el 5.1.5-10 [159 kB] 193s Get:17 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libneon27t64 ppc64el 0.34.0-1 [121 kB] 193s Get:18 http://ftpmaster.internal/ubuntu plucky/main ppc64el libltdl7 ppc64el 2.4.7-8 [47.9 kB] 193s Get:19 http://ftpmaster.internal/ubuntu plucky/main ppc64el libodbc2 ppc64el 2.3.12-1ubuntu1 [187 kB] 193s Get:20 http://ftpmaster.internal/ubuntu plucky/main ppc64el libogg0 ppc64el 1.3.5-3build1 [27.6 kB] 193s Get:21 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopencore-amrnb0 ppc64el 0.1.6-1build1 [165 kB] 193s Get:22 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopencore-amrwb0 ppc64el 0.1.6-1build1 [91.2 kB] 193s Get:23 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopusenc0 ppc64el 0.2.1-2build1 [34.5 kB] 193s Get:24 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopusfile0 ppc64el 0.12-4build3 [60.6 kB] 193s Get:25 http://ftpmaster.internal/ubuntu plucky/main ppc64el libasound2-data all 1.2.12-1 [21.0 kB] 193s Get:26 http://ftpmaster.internal/ubuntu plucky/main ppc64el libasound2t64 ppc64el 1.2.12-1 [493 kB] 193s Get:27 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libportaudio2 ppc64el 19.6.0-1.2build3 [87.5 kB] 193s Get:28 http://ftpmaster.internal/ubuntu plucky/main ppc64el libpq5 ppc64el 17.2-1 [173 kB] 193s Get:29 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libradcli4 ppc64el 1.2.11-1build3 [45.5 kB] 193s Get:30 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libresample1 ppc64el 0.1.3-8 [10.9 kB] 193s Get:31 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsnmp-base all 5.9.4+dfsg-1.1ubuntu5 [206 kB] 194s Get:32 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsnmp40t64 ppc64el 5.9.4+dfsg-1.1ubuntu5 [1171 kB] 194s Get:33 http://ftpmaster.internal/ubuntu plucky/main ppc64el libdeflate0 ppc64el 1.22-1 [63.3 kB] 194s Get:34 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjbig0 ppc64el 2.1-6.1ubuntu2 [35.9 kB] 194s Get:35 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjpeg-turbo8 ppc64el 2.1.5-3ubuntu2 [215 kB] 194s Get:36 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjpeg8 ppc64el 8c-2ubuntu11 [2148 B] 194s Get:37 http://ftpmaster.internal/ubuntu plucky/main ppc64el liblerc4 ppc64el 4.0.0+ds-5ubuntu1 [298 kB] 194s Get:38 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsharpyuv0 ppc64el 1.4.0-0.1 [22.0 kB] 194s Get:39 http://ftpmaster.internal/ubuntu plucky/main ppc64el libwebp7 ppc64el 1.4.0-0.1 [309 kB] 194s Get:40 http://ftpmaster.internal/ubuntu plucky/main ppc64el libtiff6 ppc64el 4.5.1+git230720-4ubuntu4 [272 kB] 194s Get:41 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libspandsp2t64 ppc64el 0.0.6+dfsg-2.1build1 [399 kB] 194s Get:42 http://ftpmaster.internal/ubuntu plucky/main ppc64el libspeex1 ppc64el 1.2.1-3 [108 kB] 194s Get:43 http://ftpmaster.internal/ubuntu plucky/main ppc64el libspeexdsp1 ppc64el 1.2.1-1ubuntu3 [75.0 kB] 194s Get:44 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libsrtp2-1 ppc64el 2.5.0-3build1 [51.4 kB] 194s Get:45 http://ftpmaster.internal/ubuntu plucky/main ppc64el freetds-common all 1.3.17+ds-2build3 [26.9 kB] 194s Get:46 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsybdb5 ppc64el 1.3.17+ds-2build3 [238 kB] 194s Get:47 http://ftpmaster.internal/ubuntu plucky/main ppc64el libevent-2.1-7t64 ppc64el 2.1.12-stable-10 [172 kB] 194s Get:48 http://ftpmaster.internal/ubuntu plucky/main ppc64el libunbound8 ppc64el 1.20.0-1ubuntu2.1 [546 kB] 194s Get:49 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libvo-amrwbenc0 ppc64el 0.1.3-2build1 [126 kB] 194s Get:50 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbis0a ppc64el 1.3.7-2 [142 kB] 194s Get:51 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbisenc2 ppc64el 1.3.7-2 [86.2 kB] 194s Get:52 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbisfile3 ppc64el 1.3.7-2 [22.5 kB] 194s Get:53 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-modules ppc64el 1:22.1.0~dfsg+~cs6.14.60671435-1 [3163 kB] 194s Get:54 http://ftpmaster.internal/ubuntu plucky/universe ppc64el liburiparser1 ppc64el 0.9.8+dfsg-2 [52.7 kB] 194s Get:55 http://ftpmaster.internal/ubuntu plucky/main ppc64el libxslt1.1 ppc64el 1.1.39-0exp1ubuntu2 [191 kB] 194s Get:56 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk ppc64el 1:22.1.0~dfsg+~cs6.14.60671435-1 [2811 kB] 194s Get:57 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-tests ppc64el 1:22.1.0~dfsg+~cs6.14.60671435-1 [577 kB] 194s Get:58 http://ftpmaster.internal/ubuntu plucky/main ppc64el libxml2-utils ppc64el 2.12.7+dfsg+really2.9.14-0.2ubuntu2 [41.9 kB] 195s Fetched 30.9 MB in 2s (12.9 MB/s) 195s Selecting previously unselected package asterisk-config. 195s (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 ... 74036 files and directories currently installed.) 195s Preparing to unpack .../00-asterisk-config_1%3a22.1.0~dfsg+~cs6.14.60671435-1_all.deb ... 195s Unpacking asterisk-config (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 195s Selecting previously unselected package asterisk-core-sounds-en-gsm. 195s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 195s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 195s Selecting previously unselected package asterisk-core-sounds-en. 195s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 195s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 195s Selecting previously unselected package mlock. 195s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7.1_ppc64el.deb ... 195s Unpacking mlock (8:2007f~dfsg-7.1) ... 195s Selecting previously unselected package libc-client2007e. 195s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7.1_ppc64el.deb ... 195s Unpacking libc-client2007e (8:2007f~dfsg-7.1) ... 195s Selecting previously unselected package libcodec2-1.2:ppc64el. 195s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2build1_ppc64el.deb ... 195s Unpacking libcodec2-1.2:ppc64el (1.2.0-2build1) ... 195s Selecting previously unselected package libgmime-3.0-0t64:ppc64el. 195s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.15+dfsg-1_ppc64el.deb ... 195s Unpacking libgmime-3.0-0t64:ppc64el (3.2.15+dfsg-1) ... 195s Selecting previously unselected package libgsm1:ppc64el. 195s Preparing to unpack .../07-libgsm1_1.0.22-1build1_ppc64el.deb ... 195s Unpacking libgsm1:ppc64el (1.0.22-1build1) ... 195s Selecting previously unselected package libical3t64:ppc64el. 195s Preparing to unpack .../08-libical3t64_3.0.19-1build1_ppc64el.deb ... 195s Unpacking libical3t64:ppc64el (3.0.19-1build1) ... 195s Selecting previously unselected package libiksemel3:ppc64el. 195s Preparing to unpack .../09-libiksemel3_1.4-4build2_ppc64el.deb ... 195s Unpacking libiksemel3:ppc64el (1.4-4build2) ... 195s Selecting previously unselected package libopus0:ppc64el. 195s Preparing to unpack .../10-libopus0_1.5.2-2_ppc64el.deb ... 195s Unpacking libopus0:ppc64el (1.5.2-2) ... 195s Selecting previously unselected package libsamplerate0:ppc64el. 195s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_ppc64el.deb ... 195s Unpacking libsamplerate0:ppc64el (0.2.2-4build1) ... 195s Selecting previously unselected package libjack-jackd2-0:ppc64el. 195s Preparing to unpack .../12-libjack-jackd2-0_1.9.22~dfsg-4_ppc64el.deb ... 195s Unpacking libjack-jackd2-0:ppc64el (1.9.22~dfsg-4) ... 196s Selecting previously unselected package libb64-0d:ppc64el. 196s Preparing to unpack .../13-libb64-0d_1.2-5build1_ppc64el.deb ... 196s Unpacking libb64-0d:ppc64el (1.2-5build1) ... 196s Selecting previously unselected package libjwt2:ppc64el. 196s Preparing to unpack .../14-libjwt2_1.17.2-1_ppc64el.deb ... 196s Unpacking libjwt2:ppc64el (1.17.2-1) ... 196s Selecting previously unselected package liblua5.1-0:ppc64el. 196s Preparing to unpack .../15-liblua5.1-0_5.1.5-10_ppc64el.deb ... 196s Unpacking liblua5.1-0:ppc64el (5.1.5-10) ... 196s Selecting previously unselected package libneon27t64:ppc64el. 196s Preparing to unpack .../16-libneon27t64_0.34.0-1_ppc64el.deb ... 196s Unpacking libneon27t64:ppc64el (0.34.0-1) ... 196s Selecting previously unselected package libltdl7:ppc64el. 196s Preparing to unpack .../17-libltdl7_2.4.7-8_ppc64el.deb ... 196s Unpacking libltdl7:ppc64el (2.4.7-8) ... 196s Selecting previously unselected package libodbc2:ppc64el. 196s Preparing to unpack .../18-libodbc2_2.3.12-1ubuntu1_ppc64el.deb ... 196s Unpacking libodbc2:ppc64el (2.3.12-1ubuntu1) ... 196s Selecting previously unselected package libogg0:ppc64el. 196s Preparing to unpack .../19-libogg0_1.3.5-3build1_ppc64el.deb ... 196s Unpacking libogg0:ppc64el (1.3.5-3build1) ... 196s Selecting previously unselected package libopencore-amrnb0:ppc64el. 196s Preparing to unpack .../20-libopencore-amrnb0_0.1.6-1build1_ppc64el.deb ... 196s Unpacking libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 196s Selecting previously unselected package libopencore-amrwb0:ppc64el. 196s Preparing to unpack .../21-libopencore-amrwb0_0.1.6-1build1_ppc64el.deb ... 196s Unpacking libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 196s Selecting previously unselected package libopusenc0:ppc64el. 196s Preparing to unpack .../22-libopusenc0_0.2.1-2build1_ppc64el.deb ... 196s Unpacking libopusenc0:ppc64el (0.2.1-2build1) ... 196s Selecting previously unselected package libopusfile0:ppc64el. 196s Preparing to unpack .../23-libopusfile0_0.12-4build3_ppc64el.deb ... 196s Unpacking libopusfile0:ppc64el (0.12-4build3) ... 196s Selecting previously unselected package libasound2-data. 196s Preparing to unpack .../24-libasound2-data_1.2.12-1_all.deb ... 196s Unpacking libasound2-data (1.2.12-1) ... 196s Selecting previously unselected package libasound2t64:ppc64el. 196s Preparing to unpack .../25-libasound2t64_1.2.12-1_ppc64el.deb ... 196s Unpacking libasound2t64:ppc64el (1.2.12-1) ... 196s Selecting previously unselected package libportaudio2:ppc64el. 196s Preparing to unpack .../26-libportaudio2_19.6.0-1.2build3_ppc64el.deb ... 196s Unpacking libportaudio2:ppc64el (19.6.0-1.2build3) ... 196s Selecting previously unselected package libpq5:ppc64el. 196s Preparing to unpack .../27-libpq5_17.2-1_ppc64el.deb ... 196s Unpacking libpq5:ppc64el (17.2-1) ... 196s Selecting previously unselected package libradcli4. 196s Preparing to unpack .../28-libradcli4_1.2.11-1build3_ppc64el.deb ... 196s Unpacking libradcli4 (1.2.11-1build3) ... 196s Selecting previously unselected package libresample1. 196s Preparing to unpack .../29-libresample1_0.1.3-8_ppc64el.deb ... 196s Unpacking libresample1 (0.1.3-8) ... 196s Selecting previously unselected package libsnmp-base. 196s Preparing to unpack .../30-libsnmp-base_5.9.4+dfsg-1.1ubuntu5_all.deb ... 196s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu5) ... 196s Selecting previously unselected package libsnmp40t64:ppc64el. 196s Preparing to unpack .../31-libsnmp40t64_5.9.4+dfsg-1.1ubuntu5_ppc64el.deb ... 196s Unpacking libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu5) ... 196s Selecting previously unselected package libdeflate0:ppc64el. 196s Preparing to unpack .../32-libdeflate0_1.22-1_ppc64el.deb ... 196s Unpacking libdeflate0:ppc64el (1.22-1) ... 196s Selecting previously unselected package libjbig0:ppc64el. 196s Preparing to unpack .../33-libjbig0_2.1-6.1ubuntu2_ppc64el.deb ... 196s Unpacking libjbig0:ppc64el (2.1-6.1ubuntu2) ... 196s Selecting previously unselected package libjpeg-turbo8:ppc64el. 196s Preparing to unpack .../34-libjpeg-turbo8_2.1.5-3ubuntu2_ppc64el.deb ... 196s Unpacking libjpeg-turbo8:ppc64el (2.1.5-3ubuntu2) ... 196s Selecting previously unselected package libjpeg8:ppc64el. 196s Preparing to unpack .../35-libjpeg8_8c-2ubuntu11_ppc64el.deb ... 196s Unpacking libjpeg8:ppc64el (8c-2ubuntu11) ... 196s Selecting previously unselected package liblerc4:ppc64el. 196s Preparing to unpack .../36-liblerc4_4.0.0+ds-5ubuntu1_ppc64el.deb ... 196s Unpacking liblerc4:ppc64el (4.0.0+ds-5ubuntu1) ... 196s Selecting previously unselected package libsharpyuv0:ppc64el. 196s Preparing to unpack .../37-libsharpyuv0_1.4.0-0.1_ppc64el.deb ... 196s Unpacking libsharpyuv0:ppc64el (1.4.0-0.1) ... 196s Selecting previously unselected package libwebp7:ppc64el. 196s Preparing to unpack .../38-libwebp7_1.4.0-0.1_ppc64el.deb ... 196s Unpacking libwebp7:ppc64el (1.4.0-0.1) ... 196s Selecting previously unselected package libtiff6:ppc64el. 196s Preparing to unpack .../39-libtiff6_4.5.1+git230720-4ubuntu4_ppc64el.deb ... 196s Unpacking libtiff6:ppc64el (4.5.1+git230720-4ubuntu4) ... 196s Selecting previously unselected package libspandsp2t64:ppc64el. 196s Preparing to unpack .../40-libspandsp2t64_0.0.6+dfsg-2.1build1_ppc64el.deb ... 196s Unpacking libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 196s Selecting previously unselected package libspeex1:ppc64el. 196s Preparing to unpack .../41-libspeex1_1.2.1-3_ppc64el.deb ... 196s Unpacking libspeex1:ppc64el (1.2.1-3) ... 196s Selecting previously unselected package libspeexdsp1:ppc64el. 196s Preparing to unpack .../42-libspeexdsp1_1.2.1-1ubuntu3_ppc64el.deb ... 196s Unpacking libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 196s Selecting previously unselected package libsrtp2-1:ppc64el. 196s Preparing to unpack .../43-libsrtp2-1_2.5.0-3build1_ppc64el.deb ... 196s Unpacking libsrtp2-1:ppc64el (2.5.0-3build1) ... 196s Selecting previously unselected package freetds-common. 196s Preparing to unpack .../44-freetds-common_1.3.17+ds-2build3_all.deb ... 196s Unpacking freetds-common (1.3.17+ds-2build3) ... 196s Selecting previously unselected package libsybdb5:ppc64el. 196s Preparing to unpack .../45-libsybdb5_1.3.17+ds-2build3_ppc64el.deb ... 196s Unpacking libsybdb5:ppc64el (1.3.17+ds-2build3) ... 196s Selecting previously unselected package libevent-2.1-7t64:ppc64el. 196s Preparing to unpack .../46-libevent-2.1-7t64_2.1.12-stable-10_ppc64el.deb ... 196s Unpacking libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 196s Selecting previously unselected package libunbound8:ppc64el. 196s Preparing to unpack .../47-libunbound8_1.20.0-1ubuntu2.1_ppc64el.deb ... 196s Unpacking libunbound8:ppc64el (1.20.0-1ubuntu2.1) ... 196s Selecting previously unselected package libvo-amrwbenc0:ppc64el. 196s Preparing to unpack .../48-libvo-amrwbenc0_0.1.3-2build1_ppc64el.deb ... 196s Unpacking libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 196s Selecting previously unselected package libvorbis0a:ppc64el. 196s Preparing to unpack .../49-libvorbis0a_1.3.7-2_ppc64el.deb ... 196s Unpacking libvorbis0a:ppc64el (1.3.7-2) ... 196s Selecting previously unselected package libvorbisenc2:ppc64el. 196s Preparing to unpack .../50-libvorbisenc2_1.3.7-2_ppc64el.deb ... 196s Unpacking libvorbisenc2:ppc64el (1.3.7-2) ... 196s Selecting previously unselected package libvorbisfile3:ppc64el. 196s Preparing to unpack .../51-libvorbisfile3_1.3.7-2_ppc64el.deb ... 196s Unpacking libvorbisfile3:ppc64el (1.3.7-2) ... 196s Selecting previously unselected package asterisk-modules. 196s Preparing to unpack .../52-asterisk-modules_1%3a22.1.0~dfsg+~cs6.14.60671435-1_ppc64el.deb ... 196s Unpacking asterisk-modules (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Selecting previously unselected package liburiparser1:ppc64el. 197s Preparing to unpack .../53-liburiparser1_0.9.8+dfsg-2_ppc64el.deb ... 197s Unpacking liburiparser1:ppc64el (0.9.8+dfsg-2) ... 197s Selecting previously unselected package libxslt1.1:ppc64el. 197s Preparing to unpack .../54-libxslt1.1_1.1.39-0exp1ubuntu2_ppc64el.deb ... 197s Unpacking libxslt1.1:ppc64el (1.1.39-0exp1ubuntu2) ... 197s Selecting previously unselected package asterisk. 197s Preparing to unpack .../55-asterisk_1%3a22.1.0~dfsg+~cs6.14.60671435-1_ppc64el.deb ... 197s Unpacking asterisk (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Selecting previously unselected package asterisk-tests. 197s Preparing to unpack .../56-asterisk-tests_1%3a22.1.0~dfsg+~cs6.14.60671435-1_ppc64el.deb ... 197s Unpacking asterisk-tests (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Selecting previously unselected package libxml2-utils. 197s Preparing to unpack .../57-libxml2-utils_2.12.7+dfsg+really2.9.14-0.2ubuntu2_ppc64el.deb ... 197s Unpacking libxml2-utils (2.12.7+dfsg+really2.9.14-0.2ubuntu2) ... 197s Setting up libsharpyuv0:ppc64el (1.4.0-0.1) ... 197s Setting up libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 197s Setting up libneon27t64:ppc64el (0.34.0-1) ... 197s Setting up libogg0:ppc64el (1.3.5-3build1) ... 197s Setting up liblerc4:ppc64el (4.0.0+ds-5ubuntu1) ... 197s Setting up libspeex1:ppc64el (1.2.1-3) ... 197s Setting up libgsm1:ppc64el (1.0.22-1build1) ... 197s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 197s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu5) ... 197s Setting up libcodec2-1.2:ppc64el (1.2.0-2build1) ... 197s Setting up mlock (8:2007f~dfsg-7.1) ... 197s Setting up libsrtp2-1:ppc64el (2.5.0-3build1) ... 197s Setting up libpq5:ppc64el (17.2-1) ... 197s Setting up libdeflate0:ppc64el (1.22-1) ... 197s Setting up libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 197s Setting up libb64-0d:ppc64el (1.2-5build1) ... 197s Setting up libjwt2:ppc64el (1.17.2-1) ... 197s Setting up libjbig0:ppc64el (2.1-6.1ubuntu2) ... 197s Setting up libasound2-data (1.2.12-1) ... 197s Setting up libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 197s Setting up libunbound8:ppc64el (1.20.0-1ubuntu2.1) ... 197s Setting up libasound2t64:ppc64el (1.2.12-1) ... 197s Setting up libradcli4 (1.2.11-1build3) ... 197s Setting up libopus0:ppc64el (1.5.2-2) ... 197s Setting up asterisk-config (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Setting up libvorbis0a:ppc64el (1.3.7-2) ... 197s Setting up libical3t64:ppc64el (3.0.19-1build1) ... 197s Setting up libjpeg-turbo8:ppc64el (2.1.5-3ubuntu2) ... 197s Setting up libltdl7:ppc64el (2.4.7-8) ... 197s Setting up asterisk-core-sounds-en (1.6.1-1) ... 197s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 197s 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 197s Setting up libwebp7:ppc64el (1.4.0-0.1) ... 197s Setting up libiksemel3:ppc64el (1.4-4build2) ... 197s Setting up libodbc2:ppc64el (2.3.12-1ubuntu1) ... 197s Setting up liburiparser1:ppc64el (0.9.8+dfsg-2) ... 197s Setting up libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 197s Setting up liblua5.1-0:ppc64el (5.1.5-10) ... 197s Setting up libxslt1.1:ppc64el (1.1.39-0exp1ubuntu2) ... 197s Setting up libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 197s Setting up libc-client2007e (8:2007f~dfsg-7.1) ... 197s Setting up libresample1 (0.1.3-8) ... 197s Setting up freetds-common (1.3.17+ds-2build3) ... 197s Setting up libxml2-utils (2.12.7+dfsg+really2.9.14-0.2ubuntu2) ... 197s Setting up libgmime-3.0-0t64:ppc64el (3.2.15+dfsg-1) ... 197s Setting up libsamplerate0:ppc64el (0.2.2-4build1) ... 197s Setting up libopusfile0:ppc64el (0.12-4build3) ... 197s Setting up libvorbisenc2:ppc64el (1.3.7-2) ... 197s Setting up libjpeg8:ppc64el (8c-2ubuntu11) ... 197s Setting up libopusenc0:ppc64el (0.2.1-2build1) ... 197s Setting up libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu5) ... 197s Setting up libsybdb5:ppc64el (1.3.17+ds-2build3) ... 197s Setting up libvorbisfile3:ppc64el (1.3.7-2) ... 197s Setting up libjack-jackd2-0:ppc64el (1.9.22~dfsg-4) ... 197s Setting up libtiff6:ppc64el (4.5.1+git230720-4ubuntu4) ... 197s Setting up libportaudio2:ppc64el (19.6.0-1.2build3) ... 197s Setting up libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 197s Setting up asterisk-modules (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Setting up asterisk (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 197s Adding system user for Asterisk 197s info: Adding user `asterisk' to group `dialout' ... 197s info: Adding user `asterisk' to group `audio' ... 198s Created symlink '/etc/systemd/system/multi-user.target.wants/asterisk.service' → '/usr/lib/systemd/system/asterisk.service'. 199s Setting up asterisk-tests (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 199s Processing triggers for libc-bin (2.40-4ubuntu1) ... 199s Processing triggers for man-db (2.13.0-1) ... 202s autopkgtest [09:03:52]: test asttestmods: [----------------------- 203s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 205s 'U' option is not compatible with remote console mode and has no effect. 205s 205s Asterisk has fully booted. 205s 'U' option is not compatible with remote console mode and has no effect. 205s 205s Running all available tests... 205s 205s START /apps/app_gosub/ - gosub application 205s END /apps/app_gosub/ - gosub application Time: <1ms Result: PASS 205s START /apps/app_voicemail/ - test_voicemail_vm_info 205s END /apps/app_voicemail/ - test_voicemail_vm_info Time: <1ms Result: PASS 205s START /apps/app_voicemail/ - test_voicemail_load_config 205s END /apps/app_voicemail/ - test_voicemail_load_config Time: <1ms Result: PASS 205s START /apps/app_voicemail/ - test_voicemail_notify_endl 205s END /apps/app_voicemail/ - test_voicemail_notify_endl Time: 7ms Result: PASS 205s START /apps/app_voicemail/ - vmuser 205s END /apps/app_voicemail/ - vmuser Time: <1ms Result: PASS 205s START /apps/app_voicemail/ - test_voicemail_msgcount 205s END /apps/app_voicemail/ - test_voicemail_msgcount Time: 52ms Result: PASS 205s START /apps/app_voicemail/ - vmsayname_exec 205s [app_voicemail.c:test_voicemail_vmsayname:15701]: Test playing of extension when greeting is not available... 209s [app_voicemail.c:test_voicemail_vmsayname:15722]: Test playing created mailbox greeting... 213s END /apps/app_voicemail/ - vmsayname_exec Time: 8886ms Result: PASS 213s START /ari/validators/ - validate_list 213s END /ari/validators/ - validate_list Time: <1ms Result: PASS 213s START /ari/validators/ - validate_date 213s END /ari/validators/ - validate_date Time: <1ms Result: PASS 213s START /ari/validators/ - validate_string 213s END /ari/validators/ - validate_string Time: <1ms Result: PASS 213s START /ari/validators/ - validate_long 213s END /ari/validators/ - validate_long Time: <1ms Result: PASS 213s START /ari/validators/ - validate_int 213s END /ari/validators/ - validate_int Time: <1ms Result: PASS 213s START /ari/validators/ - validate_boolean 213s END /ari/validators/ - validate_boolean Time: <1ms Result: PASS 213s START /ari/validators/ - validate_byte 213s END /ari/validators/ - validate_byte Time: <1ms Result: PASS 213s START /bridges/bridge_softmix/ - sfu_remove_destination_streams 213s END /bridges/bridge_softmix/ - sfu_remove_destination_streams Time: <1ms Result: PASS 213s START /bridges/bridge_softmix/ - sfu_append_source_streams 213s END /bridges/bridge_softmix/ - sfu_append_source_streams Time: <1ms Result: PASS 213s START /channels/features/ - test_features_channel_interval 217s END /channels/features/ - test_features_channel_interval Time: 3001ms Result: PASS 217s START /channels/features/ - test_features_channel_dtmf 219s END /channels/features/ - test_features_channel_dtmf Time: 2012ms Result: PASS 219s START /config/ - config_options_test 219s END /config/ - config_options_test Time: <1ms Result: PASS 219s START /config/ - ast_parse_arg 219s END /config/ - ast_parse_arg Time: <1ms Result: PASS 219s START /core/endpoints/ - setters 219s END /core/endpoints/ - setters Time: <1ms Result: PASS 219s START /core/endpoints/ - defaults 219s END /core/endpoints/ - defaults Time: <1ms Result: PASS 219s START /core/endpoints/ - create 219s END /core/endpoints/ - create Time: <1ms Result: PASS 219s START /funcs/func_curl/ - vulnerable_url 219s END /funcs/func_curl/ - vulnerable_url Time: <1ms Result: PASS 219s START /funcs/func_env/ - func_file 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=a'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=a'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=a'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,1)=b'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,1)=b'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5,-3)=b'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4,-3)=b'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2)=c'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,2)=c'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-7)=c'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-7)=c'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,2)=d'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,2)=d'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,4,-3)=d'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-5,-3)=d'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)=e'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,5)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)=e'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-4)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=fg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-8)=fg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,1)=fg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-9,-8)=fg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,)=h'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,,)=h'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,l)=h'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,ld)=h'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abc'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=ab'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefg'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,2,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,2,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-1,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-1,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,2,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,2,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,,l)=abcdefghijklmnop'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,2,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-1,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,3,0,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,,,la)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,l)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,-2,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-3,-2,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,1,-1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,-2,-1,ld)='... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=a'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,10)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=abcd'... OK! 219s [test_func_file.c:test_func_file:375]: Expression 'FILE(...,0,1,l)=a'... OK! 219s END /funcs/func_env/ - func_file Time: 46ms Result: PASS 219s START /funcs/func_json/ - func_JSON_DECODE 219s END /funcs/func_json/ - func_JSON_DECODE Time: <1ms Result: PASS 219s START /funcs/func_presence/ - test_presence_state_base64_encode 219s END /funcs/func_presence/ - test_presence_state_base64_encode Time: 6ms Result: PASS 219s START /funcs/func_presence/ - test_presence_state_change 219s END /funcs/func_presence/ - test_presence_state_change Time: <1ms Result: PASS 219s START /funcs/func_presence/ - parse_invalid_presence_data 219s END /funcs/func_presence/ - parse_invalid_presence_data Time: <1ms Result: PASS 219s START /funcs/func_presence/ - parse_valid_presence_data 219s END /funcs/func_presence/ - parse_valid_presence_data Time: <1ms Result: PASS 219s START /funcs/func_sayfiles/ - test_SAYFILES_function 219s [func_sayfiles.c:test_SAYFILES_function:180]: Testing SAYFILES() substitution ... 219s END /funcs/func_sayfiles/ - test_SAYFILES_function Time: 7ms Result: PASS 219s START /funcs/func_strings/ - func_TRIM 219s END /funcs/func_strings/ - func_TRIM Time: <1ms Result: PASS 219s START /funcs/func_strings/ - func_STRBETWEEN 219s END /funcs/func_strings/ - func_STRBETWEEN Time: <1ms Result: PASS 219s START /funcs/func_strings/ - func_STRREPLACE_test 219s END /funcs/func_strings/ - func_STRREPLACE_test Time: <1ms Result: PASS 219s START /funcs/func_strings/ - func_FILTER_test 219s END /funcs/func_strings/ - func_FILTER_test Time: <1ms Result: PASS 219s START /funcs/func_strings/ - func_REPLACE_test 219s END /funcs/func_strings/ - func_REPLACE_test Time: <1ms Result: PASS 219s START /funcs/func_strings/ - func_FIELDNUM_test 219s END /funcs/func_strings/ - func_FIELDNUM_test Time: <1ms Result: PASS 219s START /geoloc/ - create_from_pidf 219s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1274]: ID: 'point-2d' pidf_element: 'tuple' format: 'GML' method: 'Manual' 219s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1286]: location_vars expected: shape=Point,crs=2d,pos=-34.410649 150.87651 219s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1287]: location_vars received: shape=Point,crs=2d,pos=-34.410649 150.87651 219s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1293]: usage_rules expected: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 219s [res_geolocation/geoloc_eprofile.c:validate_eprofile:1294]: usage_rules received: retransmission-allowed='no',retention-expiry='2010-11-14T20:00:00Z' 219s END /geoloc/ - create_from_pidf Time: <1ms Result: PASS 219s START /geoloc/ - create_from_uri 219s END /geoloc/ - create_from_uri Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order 219s [test_abstract_jb.c:AST_JB_FIXED_put_out_of_order:531]: Executing AST_JB_FIXED_put_out_of_order... 219s END /main/abstract_jb/ - AST_JB_FIXED_put_out_of_order Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_FIXED_put_overflow 219s [test_abstract_jb.c:AST_JB_FIXED_put_overflow:529]: Executing AST_JB_FIXED_put_overflow... 219s END /main/abstract_jb/ - AST_JB_FIXED_put_overflow Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_FIXED_put 219s [test_abstract_jb.c:AST_JB_FIXED_put:527]: Executing AST_JB_FIXED_put... 219s END /main/abstract_jb/ - AST_JB_FIXED_put Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_FIXED_put_first 219s [test_abstract_jb.c:AST_JB_FIXED_put_first:525]: Executing AST_JB_FIXED_create... 219s END /main/abstract_jb/ - AST_JB_FIXED_put_first Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_FIXED_create 219s [test_abstract_jb.c:AST_JB_FIXED_create:523]: Executing AST_JB_FIXED_create... 219s END /main/abstract_jb/ - AST_JB_FIXED_create Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order 219s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_out_of_order:521]: Executing AST_JB_ADAPTIVE_put_out_of_order... 219s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_out_of_order Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow 219s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_overflow:519]: Executing AST_JB_ADAPTIVE_put_overflow... 219s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_overflow Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put 219s [test_abstract_jb.c:AST_JB_ADAPTIVE_put:517]: Executing AST_JB_ADAPTIVE_put... 219s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first 219s [test_abstract_jb.c:AST_JB_ADAPTIVE_put_first:515]: Executing AST_JB_ADAPTIVE_create... 219s END /main/abstract_jb/ - AST_JB_ADAPTIVE_put_first Time: <1ms Result: PASS 219s START /main/abstract_jb/ - AST_JB_ADAPTIVE_create 219s [test_abstract_jb.c:AST_JB_ADAPTIVE_create:513]: Executing AST_JB_ADAPTIVE_create... 219s END /main/abstract_jb/ - AST_JB_ADAPTIVE_create Time: <1ms Result: PASS 219s START /main/acl/ - acl 219s END /main/acl/ - acl Time: <1ms Result: PASS 219s START /main/acl/ - invalid_acl 219s END /main/acl/ - invalid_acl Time: <1ms Result: PASS 219s START /main/amihooks/ - amihook_cli_send 219s END /main/amihooks/ - amihook_cli_send Time: <1ms Result: PASS 219s START /main/aoc/ - aoc_event_test 219s END /main/aoc/ - aoc_event_test Time: <1ms Result: PASS 219s START /main/aoc/ - aoc_encode_decode_test 219s END /main/aoc/ - aoc_encode_decode_test Time: <1ms Result: PASS 219s START /main/app/ - options_parsing 219s END /main/app/ - options_parsing Time: <1ms Result: PASS 219s START /main/app/ - app_group 219s [test_app.c:app_group:172]: Creating test channels with the following groups: 219s 'a groupgroupgroup', 'a groupGroupgroup', 'a group@a_category', 'a group@another!Category' 219s [test_app.c:app_group:211]: (Subtest 1) Found 4 matches as expected when examining group:'gr' category:'' 219s [test_app.c:app_group:211]: (Subtest 2) Found 1 matches as expected when examining group:'(group){2}$' category:'' 219s [test_app.c:app_group:211]: (Subtest 3) Found 4 matches as expected when examining group:'[:ascii:]' category:'' 219s [test_app.c:app_group:211]: (Subtest 4) Found 0 matches as expected when examining group:'^(NOMATCH)' category:'' 219s [test_app.c:app_group:211]: (Subtest 5) Found 2 matches as expected when examining group:'a group' category:'(gory)$' 219s [test_app.c:app_group:211]: (Subtest 6) Found 1 matches as expected when examining group:'a group' category:'[A-Z]+' 219s [test_app.c:app_group:211]: (Subtest 7) Found 0 matches as expected when examining group:'a group' category:'[[' 219s END /main/app/ - app_group Time: <1ms Result: PASS 219s START /main/ast_expr/ - expr_test 219s END /main/ast_expr/ - expr_test Time: <1ms Result: PASS 219s START /main/astdb/ - put_get_long 219s END /main/astdb/ - put_get_long Time: 85ms Result: PASS 219s START /main/astdb/ - perftest 219s END /main/astdb/ - perftest Time: 476ms Result: PASS 219s START /main/astdb/ - gettree_deltree 219s END /main/astdb/ - gettree_deltree Time: <1ms Result: PASS 219s START /main/astdb/ - put_get_del 219s END /main/astdb/ - put_get_del Time: <1ms Result: PASS 219s START /main/astobj2/ - thrash 219s [test_astobj2_thrash.c:hash_test:266]: Executing hash concurrency test... 219s END /main/astobj2/ - thrash Time: 38ms Result: PASS 219s START /main/astobj2/ - astobj2_test4 219s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 1, List containers. 219s [test_astobj2.c:test_traversal_nonsorted:1389]: Test 2, Hash containers. 219s [test_astobj2.c:test_traversal_sorted:1615]: Test 3, List containers. 219s [test_astobj2.c:test_traversal_sorted:1615]: Test 4, Hash containers. 219s [test_astobj2.c:test_traversal_sorted:1615]: Test 5, RBTree containers. 219s END /main/astobj2/ - astobj2_test4 Time: <1ms Result: PASS 219s START /main/astobj2/ - astobj2_test3 219s END /main/astobj2/ - astobj2_test3 Time: <1ms Result: PASS 219s START /main/astobj2/ - astobj2_test2 219s END /main/astobj2/ - astobj2_test2 Time: <1ms Result: PASS 219s START /main/astobj2/ - astobj2_test1 219s [test_astobj2.c:astobj2_test_1_helper:434]: Test 1, List containers (non-sorted). 219s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 219s [test_astobj2.c:astobj2_test_1_helper:434]: Test 2, List containers (sorted). 219s [test_astobj2.c:astobj2_test_1_helper:488]: List container created: buckets: 1, items: 50 219s [test_astobj2.c:astobj2_test_1_helper:434]: Test 3, Hash containers (non-sorted). 219s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 7, items: 1000 219s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, Hash containers (sorted). 219s [test_astobj2.c:astobj2_test_1_helper:488]: Hash container created: buckets: 122, items: 1000 219s [test_astobj2.c:astobj2_test_1_helper:434]: Test 4, RBTree containers (sorted). 219s [test_astobj2.c:astobj2_test_1_helper:488]: RBTree container created: buckets: 1, items: 1000 219s END /main/astobj2/ - astobj2_test1 Time: 18ms Result: PASS 219s START /main/astobj2/ - astobj2_weak_container 219s END /main/astobj2/ - astobj2_weak_container Time: <1ms Result: PASS 219s START /main/astobj2/ - astobj2_weak1 219s END /main/astobj2/ - astobj2_weak1 Time: <1ms Result: PASS 219s START /main/astobj2/perf/ - astobj2_test_perf 221s [test_astobj2.c:testloop:2001]: 20.00K traversals, List 222s [test_astobj2.c:testloop:2001]: 40.00K traversals, List 223s [test_astobj2.c:testloop:2001]: 60.00K traversals, List 225s [test_astobj2.c:testloop:2001]: 80.00K traversals, List 226s [test_astobj2.c:testloop:2006]: 100.00K traversals, List : 6839 ms 227s [test_astobj2.c:testloop:2001]: 20.00K traversals, Hash 228s [test_astobj2.c:testloop:2001]: 40.00K traversals, Hash 229s [test_astobj2.c:testloop:2001]: 60.00K traversals, Hash 230s [test_astobj2.c:testloop:2001]: 80.00K traversals, Hash 231s [test_astobj2.c:testloop:2006]: 100.00K traversals, Hash : 4914 ms 232s [test_astobj2.c:testloop:2001]: 20.00K traversals, RBTree 233s [test_astobj2.c:testloop:2001]: 40.00K traversals, RBTree 234s [test_astobj2.c:testloop:2001]: 60.00K traversals, RBTree 235s [test_astobj2.c:testloop:2001]: 80.00K traversals, RBTree 236s [test_astobj2.c:testloop:2006]: 100.00K traversals, RBTree : 5381 ms 236s END /main/astobj2/perf/ - astobj2_test_perf Time: 17135ms Result: PASS 236s START /main/bridging/ - test_bridging_deferred_queue 237s END /main/bridging/ - test_bridging_deferred_queue Time: 1015ms Result: PASS 237s START /main/bucket/ - bucket_file_json 237s END /main/bucket/ - bucket_file_json Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_metadata_get 237s END /main/bucket/ - bucket_file_metadata_get Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_metadata_unset 237s END /main/bucket/ - bucket_file_metadata_unset Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_metadata_set 237s END /main/bucket/ - bucket_file_metadata_set Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_is_stale 237s END /main/bucket/ - bucket_file_is_stale Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_delete 237s END /main/bucket/ - bucket_file_delete Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_update 237s END /main/bucket/ - bucket_file_update Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_retrieve 237s END /main/bucket/ - bucket_file_retrieve Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_copy 237s END /main/bucket/ - bucket_file_copy Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_clone 237s END /main/bucket/ - bucket_file_clone Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_create 237s END /main/bucket/ - bucket_file_create Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_file_alloc 237s END /main/bucket/ - bucket_file_alloc Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_json 237s END /main/bucket/ - bucket_json Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_is_stale 237s END /main/bucket/ - bucket_is_stale Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_retrieve 237s END /main/bucket/ - bucket_retrieve Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_delete 237s END /main/bucket/ - bucket_delete Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_clone 237s END /main/bucket/ - bucket_clone Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_create 237s END /main/bucket/ - bucket_create Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_alloc 237s END /main/bucket/ - bucket_alloc Time: <1ms Result: PASS 237s START /main/bucket/ - bucket_scheme_register_unregister 237s END /main/bucket/ - bucket_scheme_register_unregister Time: <1ms Result: PASS 237s START /main/callerid/ - parse_off_nominal 237s END /main/callerid/ - parse_off_nominal Time: <1ms Result: PASS 237s START /main/callerid/ - parse_nominal 237s END /main/callerid/ - parse_nominal Time: <1ms Result: PASS 237s START /main/cdr/ - test_cdr_fork_cdr 239s Verifying expected record CDRTestChannel/Alice, 239s Finished expected record CDRTestChannel/Alice, 239s Verifying expected record CDRTestChannel/Alice, 239s Finished expected record CDRTestChannel/Alice, 239s Verifying expected record CDRTestChannel/Alice, 239s Finished expected record CDRTestChannel/Alice, 239s END /main/cdr/ - test_cdr_fork_cdr Time: 2001ms Result: PASS 239s START /main/cdr/ - test_cdr_no_reset_cdr 240s Verifying expected record CDRTestChannel/Alice, 240s Finished expected record CDRTestChannel/Alice, 240s END /main/cdr/ - test_cdr_no_reset_cdr Time: 1000ms Result: PASS 240s START /main/cdr/ - test_cdr_fields 242s Verifying expected record CDRTestChannel/Alice, 242s Finished expected record CDRTestChannel/Alice, 242s Verifying expected record CDRTestChannel/Alice, 242s Finished expected record CDRTestChannel/Alice, 242s Verifying expected record CDRTestChannel/Alice, 242s Finished expected record CDRTestChannel/Alice, 242s END /main/cdr/ - test_cdr_fields Time: 2000ms Result: PASS 242s START /main/cdr/ - test_cdr_park 245s Verifying expected record CDRTestChannel/Alice, 245s Finished expected record CDRTestChannel/Alice, 245s Verifying expected record CDRTestChannel/Bob, 245s Finished expected record CDRTestChannel/Bob, 245s END /main/cdr/ - test_cdr_park Time: 3002ms Result: PASS 245s START /main/cdr/ - test_cdr_dial_answer_multiparty 250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 250s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 250s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 250s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/David 250s Finished expected record CDRTestChannel/Bob, CDRTestChannel/David 250s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/David 250s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/David 250s Verifying expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 250s Finished expected record CDRTestChannel/Charlie, CDRTestChannel/Bob 250s END /main/cdr/ - test_cdr_dial_answer_multiparty Time: 5004ms Result: PASS 250s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b 253s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 253s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 253s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_b Time: 3002ms Result: PASS 253s START /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_answer_twoparty_bridge_a Time: 2001ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_answer_no_bridge 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Verifying expected record CDRTestChannel/Alice, 255s Finished expected record CDRTestChannel/Alice, 255s Verifying expected record CDRTestChannel/Bob, 255s Finished expected record CDRTestChannel/Bob, 255s END /main/cdr/ - test_cdr_dial_answer_no_bridge Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_parallel_failed 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/David 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/David 255s END /main/cdr/ - test_cdr_dial_parallel_failed Time: 1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_caller_cancel 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_caller_cancel Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_unavailable 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_unavailable Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_busy 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_busy Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_congestion 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_congestion Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_dial_unanswered 255s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 255s END /main/cdr/ - test_cdr_dial_unanswered Time: <1ms Result: PASS 255s START /main/cdr/ - test_cdr_outbound_bridged_call 258s Verifying expected record CDRTestChannel/Bob, 258s Finished expected record CDRTestChannel/Bob, 258s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 258s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 258s END /main/cdr/ - test_cdr_outbound_bridged_call Time: 3002ms Result: PASS 258s START /main/cdr/ - test_cdr_single_multiparty_bridge 262s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 262s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 262s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 262s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Charlie 262s Verifying expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 262s Finished expected record CDRTestChannel/Bob, CDRTestChannel/Charlie 262s Verifying expected record CDRTestChannel/Charlie, 262s Finished expected record CDRTestChannel/Charlie, 262s END /main/cdr/ - test_cdr_single_multiparty_bridge Time: 4006ms Result: PASS 262s START /main/cdr/ - test_cdr_single_twoparty_bridge_b 265s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 265s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 265s Verifying expected record CDRTestChannel/Bob, 265s Finished expected record CDRTestChannel/Bob, 265s END /main/cdr/ - test_cdr_single_twoparty_bridge_b Time: 3002ms Result: PASS 265s START /main/cdr/ - test_cdr_single_twoparty_bridge_a 267s Verifying expected record CDRTestChannel/Alice, CDRTestChannel/Bob 267s Finished expected record CDRTestChannel/Alice, CDRTestChannel/Bob 267s Verifying expected record CDRTestChannel/Bob, 267s Finished expected record CDRTestChannel/Bob, 267s END /main/cdr/ - test_cdr_single_twoparty_bridge_a Time: 2001ms Result: PASS 267s START /main/cdr/ - test_cdr_single_bridge_continue 269s Verifying expected record CDRTestChannel/Alice, 269s Finished expected record CDRTestChannel/Alice, 269s Verifying expected record CDRTestChannel/Alice, 269s Finished expected record CDRTestChannel/Alice, 269s END /main/cdr/ - test_cdr_single_bridge_continue Time: 2001ms Result: PASS 269s START /main/cdr/ - test_cdr_single_bridge 271s Verifying expected record CDRTestChannel/Alice, 271s Finished expected record CDRTestChannel/Alice, 271s END /main/cdr/ - test_cdr_single_bridge Time: 2001ms Result: PASS 271s START /main/cdr/ - test_cdr_single_party 271s Verifying expected record CDRTestChannel/Alice, 271s Finished expected record CDRTestChannel/Alice, 271s END /main/cdr/ - test_cdr_single_party Time: <1ms Result: PASS 271s START /main/cdr/ - test_cdr_unanswered_outbound_call 271s Verifying expected record CDRTestChannel/Alice, 271s Finished expected record CDRTestChannel/Alice, 271s END /main/cdr/ - test_cdr_unanswered_outbound_call Time: <1ms Result: PASS 271s START /main/cdr/ - test_cdr_unanswered_inbound_call 271s Verifying expected record CDRTestChannel/Alice, 271s Finished expected record CDRTestChannel/Alice, 271s END /main/cdr/ - test_cdr_unanswered_inbound_call Time: <1ms Result: PASS 271s START /main/cdr/ - test_cdr_channel_creation 271s Verifying expected record CDRTestChannel/Alice, 271s Finished expected record CDRTestChannel/Alice, 271s END /main/cdr/ - test_cdr_channel_creation Time: <1ms Result: PASS 271s START /main/channel/ - add_fd 271s END /main/channel/ - add_fd Time: <1ms Result: PASS 271s START /main/channel/ - set_fd_grow 271s END /main/channel/ - set_fd_grow Time: <1ms Result: PASS 271s START /main/config/ - variable_list_from_quoted_string 271s END /main/config/ - variable_list_from_quoted_string Time: <1ms Result: PASS 271s START /main/config/ - variable_list_join_replace 271s END /main/config/ - variable_list_join_replace Time: <1ms Result: PASS 271s START /main/config/ - variable_lists_match 271s END /main/config/ - variable_lists_match Time: <1ms Result: PASS 271s START /main/config/ - config_dialplan_function 271s END /main/config/ - config_dialplan_function Time: <1ms Result: PASS 271s START /main/config/ - config_hook 271s END /main/config/ - config_hook Time: <1ms Result: PASS 271s START /main/config/ - copy_config 271s END /main/config/ - copy_config Time: <1ms Result: PASS 271s START /main/config/ - config_template_ops 271s END /main/config/ - config_template_ops Time: <1ms Result: PASS 271s START /main/config/ - config_filtered_ops 271s END /main/config/ - config_filtered_ops Time: <1ms Result: PASS 271s START /main/config/ - config_basic_ops 271s END /main/config/ - config_basic_ops Time: <1ms Result: PASS 271s START /main/config/ - config_save 271s END /main/config/ - config_save Time: 1ms Result: PASS 271s START /main/conversions/ - str_to_umax 271s END /main/conversions/ - str_to_umax Time: <1ms Result: PASS 271s START /main/conversions/ - str_to_imax 271s END /main/conversions/ - str_to_imax Time: <1ms Result: PASS 271s START /main/conversions/ - str_to_ulong 271s END /main/conversions/ - str_to_ulong Time: <1ms Result: PASS 271s START /main/conversions/ - str_to_long 271s END /main/conversions/ - str_to_long Time: <1ms Result: PASS 271s START /main/conversions/ - str_to_uint 271s END /main/conversions/ - str_to_uint Time: <1ms Result: PASS 271s START /main/conversions/ - str_to_int 271s END /main/conversions/ - str_to_int Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_get_unknown 271s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_get_unknown 271s END /main/core_codec/ - codec_get_unknown Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_get_unregistered 271s END /main/core_codec/ - codec_get_unregistered Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_get 271s END /main/core_codec/ - codec_get Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_register_audio_no_sample_rate 271s END /main/core_codec/ - codec_register_audio_no_sample_rate Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_register_unknown 271s END /main/core_codec/ - codec_register_unknown Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_register_twice 271s END /main/core_codec/ - codec_register_twice Time: <1ms Result: PASS 271s START /main/core_codec/ - codec_register 271s END /main/core_codec/ - codec_register Time: <1ms Result: PASS 271s START /main/core_format/ - format_parse_and_generate_sdp_fmtp 271s END /main/core_format/ - format_parse_and_generate_sdp_fmtp Time: <1ms Result: PASS 271s START /main/core_format/ - format_parse_sdp_fmtp_without_interface 271s END /main/core_format/ - format_parse_sdp_fmtp_without_interface Time: <1ms Result: PASS 271s START /main/core_format/ - format_attribute_get_without_interface 271s END /main/core_format/ - format_attribute_get_without_interface Time: <1ms Result: PASS 271s START /main/core_format/ - format_attribute_set_without_interface 271s END /main/core_format/ - format_attribute_set_without_interface Time: <1ms Result: PASS 271s START /main/core_format/ - format_copy 271s END /main/core_format/ - format_copy Time: <1ms Result: PASS 271s START /main/core_format/ - format_joint_different_codec 271s END /main/core_format/ - format_joint_different_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_attr_joint_same_codec 271s END /main/core_format/ - format_attr_joint_same_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_joint_same_codec 271s END /main/core_format/ - format_joint_same_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_cmp_different_codec 271s END /main/core_format/ - format_cmp_different_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_attr_cmp_same_codec 271s END /main/core_format/ - format_attr_cmp_same_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_cmp_same_codec 271s END /main/core_format/ - format_cmp_same_codec Time: <1ms Result: PASS 271s START /main/core_format/ - format_clone 271s END /main/core_format/ - format_clone Time: <1ms Result: PASS 271s START /main/core_format/ - format_retrieve_attr 271s END /main/core_format/ - format_retrieve_attr Time: <1ms Result: PASS 271s START /main/core_format/ - format_create_attr 271s END /main/core_format/ - format_create_attr Time: <1ms Result: PASS 271s START /main/core_format/ - format_create 271s END /main/core_format/ - format_create Time: <1ms Result: PASS 271s START /main/data_buffer/ - buffer_nominal 271s END /main/data_buffer/ - buffer_nominal Time: <1ms Result: PASS 271s START /main/data_buffer/ - buffer_resize 271s END /main/data_buffer/ - buffer_resize Time: <1ms Result: PASS 271s START /main/data_buffer/ - buffer_put 271s END /main/data_buffer/ - buffer_put Time: <1ms Result: PASS 271s START /main/data_buffer/ - buffer_create 271s END /main/data_buffer/ - buffer_create Time: <1ms Result: PASS 271s START /main/devicestate/ - devstate_channels 271s END /main/devicestate/ - devstate_channels Time: <1ms Result: PASS 271s START /main/devicestate/ - devstate_conversions 271s END /main/devicestate/ - devstate_conversions Time: <1ms Result: PASS 271s START /main/devicestate/ - devstate_changed 271s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 271s [test_devicestate.c:devstate_changed:716]: Testing update 0: actual is 1; expected is 1 271s [test_devicestate.c:devstate_changed:716]: Testing update 1: actual is 2; expected is 2 271s [test_devicestate.c:devstate_changed:716]: Testing update 2: actual is 3; expected is 3 271s [test_devicestate.c:devstate_changed:716]: Testing update 3: actual is 4; expected is 4 271s [test_devicestate.c:devstate_changed:716]: Testing update 4: actual is 5; expected is 5 271s [test_devicestate.c:devstate_changed:716]: Testing update 5: actual is 6; expected is 6 271s [test_devicestate.c:devstate_changed:716]: Testing update 6: actual is 7; expected is 7 271s [test_devicestate.c:devstate_changed:716]: Testing update 7: actual is 8; expected is 8 271s [test_devicestate.c:wait_for_device_state_updates:308]: Received 1 of 1 updates 271s [test_devicestate.c:wait_for_device_state_updates:308]: Received 8 of 8 updates 271s [test_devicestate.c:devstate_changed:754]: Testing update 0: actual is 1; expected is 1 271s [test_devicestate.c:devstate_changed:754]: Testing update 1: actual is 2; expected is 2 271s [test_devicestate.c:devstate_changed:754]: Testing update 2: actual is 3; expected is 3 271s [test_devicestate.c:devstate_changed:754]: Testing update 3: actual is 4; expected is 4 271s [test_devicestate.c:devstate_changed:754]: Testing update 4: actual is 5; expected is 5 271s [test_devicestate.c:devstate_changed:754]: Testing update 5: actual is 6; expected is 6 271s [test_devicestate.c:devstate_changed:754]: Testing update 6: actual is 7; expected is 7 271s [test_devicestate.c:devstate_changed:754]: Testing update 7: actual is 8; expected is 8 271s END /main/devicestate/ - devstate_changed Time: 1ms Result: PASS 271s START /main/devicestate/ - devstate_prov_del 271s END /main/devicestate/ - devstate_prov_del Time: <1ms Result: PASS 271s START /main/devicestate/ - devstate_prov_add 271s END /main/devicestate/ - devstate_prov_add Time: <1ms Result: PASS 271s START /main/devicestate/ - device2extenstate_test 271s END /main/devicestate/ - device2extenstate_test Time: <1ms Result: PASS 271s START /main/devicestate/ - device_state_aggregation_test 271s END /main/devicestate/ - device_state_aggregation_test Time: <1ms Result: PASS 271s START /main/dns/ - resolver_resolve_async_cancel 271s END /main/dns/ - resolver_resolve_async_cancel Time: <1ms Result: PASS 271s START /main/dns/ - resolver_resolve_async_off_nominal 271s END /main/dns/ - resolver_resolve_async_off_nominal Time: <1ms Result: PASS 271s START /main/dns/ - resolver_resolve_async 276s END /main/dns/ - resolver_resolve_async Time: 5000ms Result: PASS 276s START /main/dns/ - resolver_resolve_sync_off_nominal 276s END /main/dns/ - resolver_resolve_sync_off_nominal Time: <1ms Result: PASS 276s START /main/dns/ - resolver_resolve_sync 281s END /main/dns/ - resolver_resolve_sync Time: 5000ms Result: PASS 281s START /main/dns/ - resolver_add_record_off_nominal 281s END /main/dns/ - resolver_add_record_off_nominal Time: <1ms Result: PASS 281s START /main/dns/ - resolver_add_record 281s END /main/dns/ - resolver_add_record Time: <1ms Result: PASS 281s START /main/dns/ - resolver_set_result_off_nominal 281s END /main/dns/ - resolver_set_result_off_nominal Time: <1ms Result: PASS 281s START /main/dns/ - resolver_set_result 281s END /main/dns/ - resolver_set_result Time: <1ms Result: PASS 281s START /main/dns/ - resolver_data 281s END /main/dns/ - resolver_data Time: <1ms Result: PASS 281s START /main/dns/ - resolver_unregister_off_nominal 281s END /main/dns/ - resolver_unregister_off_nominal Time: <1ms Result: PASS 281s START /main/dns/ - resolver_register_off_nominal 281s END /main/dns/ - resolver_register_off_nominal Time: <1ms Result: PASS 281s START /main/dns/ - resolver_register_unregister 281s END /main/dns/ - resolver_register_unregister Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve_off_nominal_interactions 281s END /main/dns/naptr/ - naptr_resolve_off_nominal_interactions Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve_off_nominal_regexp 281s END /main/dns/naptr/ - naptr_resolve_off_nominal_regexp Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve_off_nominal_services 281s END /main/dns/naptr/ - naptr_resolve_off_nominal_services Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve_off_nominal_flags 281s END /main/dns/naptr/ - naptr_resolve_off_nominal_flags Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve_off_nominal_length 281s END /main/dns/naptr/ - naptr_resolve_off_nominal_length Time: <1ms Result: PASS 281s START /main/dns/naptr/ - naptr_resolve 281s END /main/dns/naptr/ - naptr_resolve Time: <1ms Result: PASS 281s START /main/dns/query_set/ - query_set_off_nominal_cancel 281s END /main/dns/query_set/ - query_set_off_nominal_cancel Time: <1ms Result: PASS 281s START /main/dns/query_set/ - query_set_nominal_cancel 281s END /main/dns/query_set/ - query_set_nominal_cancel Time: <1ms Result: PASS 281s START /main/dns/query_set/ - query_set_empty 281s END /main/dns/query_set/ - query_set_empty Time: <1ms Result: PASS 281s START /main/dns/query_set/ - query_set 281s END /main/dns/query_set/ - query_set Time: <1ms Result: PASS 281s START /main/dns/recurring/ - recurring_query_cancel_during 281s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 288s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 298s END /main/dns/recurring/ - recurring_query_cancel_during Time: 17000ms Result: PASS 298s START /main/dns/recurring/ - recurring_query_cancel_between 298s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 308s END /main/dns/recurring/ - recurring_query_cancel_between Time: 10000ms Result: PASS 308s START /main/dns/recurring/ - recurring_query_off_nominal 308s END /main/dns/recurring/ - recurring_query_off_nominal Time: <1ms Result: PASS 308s START /main/dns/recurring/ - recurring_query 308s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 315s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 327s [test_dns_recurring.c:wait_for_resolution:252]: Query completed in expected time frame 327s END /main/dns/recurring/ - recurring_query Time: 18999ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_record_missing_host 327s END /main/dns/srv/ - srv_resolve_record_missing_host Time: <1ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_record_missing_port_host 327s END /main/dns/srv/ - srv_resolve_record_missing_port_host Time: <1ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_record_missing_weight_port_host 327s END /main/dns/srv/ - srv_resolve_record_missing_weight_port_host Time: <1ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_different_priorities_different_weights 327s END /main/dns/srv/ - srv_resolve_different_priorities_different_weights Time: 10ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_same_priority_different_weights 327s END /main/dns/srv/ - srv_resolve_same_priority_different_weights Time: 8ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_same_priority_zero_weight 327s END /main/dns/srv/ - srv_resolve_same_priority_zero_weight Time: <1ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_sort_priority 327s END /main/dns/srv/ - srv_resolve_sort_priority Time: <1ms Result: PASS 327s START /main/dns/srv/ - srv_resolve_single_record 327s END /main/dns/srv/ - srv_resolve_single_record Time: <1ms Result: PASS 327s START /main/dsp/ - dtmf 327s END /main/dsp/ - dtmf Time: 4ms Result: PASS 327s START /main/dsp/ - fax 328s END /main/dsp/ - fax Time: 793ms Result: PASS 328s START /main/event/ - ast_event_new_test 328s [test_event.c:event_new_test:125]: First, test dynamic event creation... 328s [test_event.c:check_event:88]: Event looks good. 328s [test_event.c:check_event:88]: Event looks good. 328s END /main/event/ - ast_event_new_test Time: <1ms Result: PASS 328s START /main/file/ - read_dir_test 328s END /main/file/ - read_dir_test Time: 2ms Result: PASS 328s START /main/file/ - ast_format_str_reduce_test_1 328s END /main/file/ - ast_format_str_reduce_test_1 Time: <1ms Result: PASS 328s START /main/format_cache/ - format_cache_get_nonxistent 328s END /main/format_cache/ - format_cache_get_nonxistent Time: <1ms Result: PASS 328s START /main/format_cache/ - format_cache_get 328s END /main/format_cache/ - format_cache_get Time: <1ms Result: PASS 328s START /main/format_cache/ - format_cache_set_null 328s END /main/format_cache/ - format_cache_set_null Time: <1ms Result: PASS 328s START /main/format_cache/ - format_cache_set_duplicate 328s END /main/format_cache/ - format_cache_set_duplicate Time: <1ms Result: PASS 328s START /main/format_cache/ - format_cache_set 328s END /main/format_cache/ - format_cache_set Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_replace_from_cap 328s END /main/format_cap/ - format_cap_replace_from_cap Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_best_by_type 328s END /main/format_cap/ - format_cap_best_by_type Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_iscompatible 328s END /main/format_cap/ - format_cap_iscompatible Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_get_compatible 328s END /main/format_cap/ - format_cap_get_compatible Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_iscompatible_format 328s END /main/format_cap/ - format_cap_iscompatible_format Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_get_compatible_format 328s END /main/format_cap/ - format_cap_get_compatible_format Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_get_names 328s END /main/format_cap/ - format_cap_get_names Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_remove_all 328s END /main/format_cap/ - format_cap_remove_all Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_remove_bytype 328s END /main/format_cap/ - format_cap_remove_bytype Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_remove_multiple 328s END /main/format_cap/ - format_cap_remove_multiple Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_remove_single 328s END /main/format_cap/ - format_cap_remove_single Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_set_framing 328s END /main/format_cap/ - format_cap_set_framing Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_from_cap_duplicate 328s END /main/format_cap/ - format_cap_append_from_cap_duplicate Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_from_cap 328s END /main/format_cap/ - format_cap_append_from_cap Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_duplicate 328s END /main/format_cap/ - format_cap_append_duplicate Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_all_audio 328s END /main/format_cap/ - format_cap_append_all_audio Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_all_unknown 328s END /main/format_cap/ - format_cap_append_all_unknown Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_multiple 328s END /main/format_cap/ - format_cap_append_multiple Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_append_single 328s END /main/format_cap/ - format_cap_append_single Time: <1ms Result: PASS 328s START /main/format_cap/ - format_cap_alloc 328s END /main/format_cap/ - format_cap_alloc Time: <1ms Result: PASS 328s START /main/hashtab/ - thrash 328s [test_hashtab_thrash.c:hash_test:246]: Executing hash concurrency test... 328s END /main/hashtab/ - thrash Time: 123ms Result: PASS 328s START /main/heap/ - heap_test_3 328s END /main/heap/ - heap_test_3 Time: 134ms Result: PASS 328s START /main/heap/ - heap_test_2 329s END /main/heap/ - heap_test_2 Time: 122ms Result: PASS 329s START /main/heap/ - heap_test_1 329s END /main/heap/ - heap_test_1 Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_resynch_control 329s END /main/jitterbuf/ - jitterbuffer_resynch_control Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_resynch_voice 329s END /main/jitterbuf/ - jitterbuffer_resynch_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_overflow_control 329s END /main/jitterbuf/ - jitterbuffer_overflow_control Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_overflow_voice 329s END /main/jitterbuf/ - jitterbuffer_overflow_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_late_control 329s END /main/jitterbuf/ - jitterbuffer_late_control Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_late_voice 329s END /main/jitterbuf/ - jitterbuffer_late_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_lost_control 329s END /main/jitterbuf/ - jitterbuffer_lost_control Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_lost_voice 329s END /main/jitterbuf/ - jitterbuffer_lost_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 329s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_out_of_order_voice 329s END /main/jitterbuf/ - jitterbuffer_out_of_order_voice Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_nominal_control_frames 329s END /main/jitterbuf/ - jitterbuffer_nominal_control_frames Time: <1ms Result: PASS 329s START /main/jitterbuf/ - jitterbuffer_nominal_voice_frames 329s END /main/jitterbuf/ - jitterbuffer_nominal_voice_frames Time: <1ms Result: PASS 329s START /main/json/ - cep 329s END /main/json/ - cep Time: <1ms Result: PASS 329s START /main/json/ - type_timeval 329s END /main/json/ - type_timeval Time: 12ms Result: PASS 329s START /main/json/ - name_number 329s END /main/json/ - name_number Time: <1ms Result: PASS 329s START /main/json/ - clever_circle 329s END /main/json/ - clever_circle Time: <1ms Result: PASS 329s START /main/json/ - circular_array 329s END /main/json/ - circular_array Time: <1ms Result: PASS 329s START /main/json/ - circular_object 329s END /main/json/ - circular_object Time: <1ms Result: PASS 329s START /main/json/ - copy_null 329s END /main/json/ - copy_null Time: <1ms Result: PASS 329s START /main/json/ - deep_copy 329s END /main/json/ - deep_copy Time: <1ms Result: PASS 329s START /main/json/ - copy 329s END /main/json/ - copy Time: <1ms Result: PASS 329s START /main/json/ - object_alloc 329s END /main/json/ - object_alloc Time: 2ms Result: PASS 329s START /main/json/ - pack_ownership 329s END /main/json/ - pack_ownership Time: <1ms Result: PASS 329s START /main/json/ - pack 329s END /main/json/ - pack Time: <1ms Result: PASS 329s START /main/json/ - parse_errors 329s END /main/json/ - parse_errors Time: <1ms Result: PASS 329s START /main/json/ - dump_load_null 329s END /main/json/ - dump_load_null Time: <1ms Result: PASS 329s START /main/json/ - dump_load_new_file 329s END /main/json/ - dump_load_new_file Time: 4ms Result: PASS 329s START /main/json/ - dump_load_file 329s END /main/json/ - dump_load_file Time: 1ms Result: PASS 329s START /main/json/ - load_buffer 329s END /main/json/ - load_buffer Time: <1ms Result: PASS 329s START /main/json/ - dump_str_fail 329s END /main/json/ - dump_str_fail Time: <1ms Result: PASS 329s START /main/json/ - dump_load_str 329s END /main/json/ - dump_load_str Time: <1ms Result: PASS 329s START /main/json/ - dump_load_string 329s END /main/json/ - dump_load_string Time: <1ms Result: PASS 329s START /main/json/ - object_create_vars 329s END /main/json/ - object_create_vars Time: <1ms Result: PASS 329s START /main/json/ - object_iter_null 329s END /main/json/ - object_iter_null Time: <1ms Result: PASS 329s START /main/json/ - object_iter 329s END /main/json/ - object_iter Time: <1ms Result: PASS 329s START /main/json/ - object_null 329s END /main/json/ - object_null Time: <1ms Result: PASS 329s START /main/json/ - object_merge_missing 329s END /main/json/ - object_merge_missing Time: <1ms Result: PASS 329s START /main/json/ - object_alloc 329s END /main/json/ - object_alloc Time: <1ms Result: PASS 329s START /main/json/ - object_alloc 329s END /main/json/ - object_alloc Time: <1ms Result: PASS 329s START /main/json/ - object_clear 329s END /main/json/ - object_clear Time: <1ms Result: PASS 329s START /main/json/ - object_del 329s END /main/json/ - object_del Time: <1ms Result: PASS 329s START /main/json/ - object_get 329s END /main/json/ - object_get Time: <1ms Result: PASS 329s START /main/json/ - object_set_overwriting 329s END /main/json/ - object_set_overwriting Time: <1ms Result: PASS 329s START /main/json/ - object_set 329s END /main/json/ - object_set Time: <1ms Result: PASS 329s START /main/json/ - object_alloc 329s END /main/json/ - object_alloc Time: <1ms Result: PASS 329s START /main/json/ - array_null 329s END /main/json/ - array_null Time: <1ms Result: PASS 329s START /main/json/ - array_extend 329s END /main/json/ - array_extend Time: <1ms Result: PASS 329s START /main/json/ - array_clear 329s END /main/json/ - array_clear Time: <1ms Result: PASS 329s START /main/json/ - array_remove 329s END /main/json/ - array_remove Time: 1ms Result: PASS 329s START /main/json/ - array_set 329s END /main/json/ - array_set Time: <1ms Result: PASS 329s START /main/json/ - array_insert 329s END /main/json/ - array_insert Time: <1ms Result: PASS 329s START /main/json/ - array_append 329s END /main/json/ - array_append Time: <1ms Result: PASS 329s START /main/json/ - array_create 329s END /main/json/ - array_create Time: <1ms Result: PASS 329s START /main/json/ - non_int 329s END /main/json/ - non_int Time: <1ms Result: PASS 329s START /main/json/ - type_int 329s END /main/json/ - type_int Time: <1ms Result: PASS 329s START /main/json/ - stringf 329s END /main/json/ - stringf Time: <1ms Result: PASS 329s START /main/json/ - string_null 329s END /main/json/ - string_null Time: <1ms Result: PASS 329s START /main/json/ - type_string 329s END /main/json/ - type_string Time: <1ms Result: PASS 329s START /main/json/ - null_val 329s END /main/json/ - null_val Time: <1ms Result: PASS 329s START /main/json/ - type_null 329s END /main/json/ - type_null Time: <1ms Result: PASS 329s START /main/json/ - type_bool1 329s END /main/json/ - type_bool1 Time: <1ms Result: PASS 329s START /main/json/ - type_bool0 329s END /main/json/ - type_bool0 Time: <1ms Result: PASS 329s START /main/json/ - type_true 329s END /main/json/ - type_true Time: <1ms Result: PASS 329s START /main/json/ - type_false 329s END /main/json/ - type_false Time: <1ms Result: PASS 329s START /main/linkedlists/ - double_ll_tests 329s END /main/linkedlists/ - double_ll_tests Time: <1ms Result: PASS 329s START /main/linkedlists/ - ll_tests 329s END /main/linkedlists/ - ll_tests Time: <1ms Result: PASS 329s START /main/lock/ - cleanup_order_test 329s [test_scoped_lock.c:test_ref:149]: Ref is occurring 329s [test_scoped_lock.c:test_lock:117]: Lock is occurring 329s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 329s [test_scoped_lock.c:test_unref:166]: Unref is occurring 329s [test_scoped_lock.c:test_ref:149]: Ref is occurring 329s [test_scoped_lock.c:test_lock:117]: Lock is occurring 329s [test_scoped_lock.c:test_unlock:133]: Unlock is occurring 329s [test_scoped_lock.c:test_unref:166]: Unref is occurring 329s END /main/lock/ - cleanup_order_test Time: <1ms Result: PASS 329s START /main/lock/ - lock_test 329s END /main/lock/ - lock_test Time: <1ms Result: PASS 329s START /main/lock/ - named_lock_test 329s [test_named_lock.c:named_lock_test:80]: This test should take about 3 seconds 332s END /main/lock/ - named_lock_test Time: 3001ms Result: PASS 332s START /main/logging/ - scope_test 332s END /main/logging/ - scope_test Time: <1ms Result: PASS 332s START /main/manager/ - originate_permissions_test 332s END /main/manager/ - originate_permissions_test Time: <1ms Result: PASS 332s START /main/manager/ - eventfilter_test_matching 332s Loaded 7 filters 332s Tested 9 events 332s END /main/manager/ - eventfilter_test_matching Time: <1ms Result: PASS 332s START /main/manager/ - eventfilter_test_creation 332s [manager.c:eventfilter_test_creation:6189]: Tested 29 filters 332s END /main/manager/ - eventfilter_test_creation Time: <1ms Result: PASS 332s START /main/media_cache/ - create_update_off_nominal 332s END /main/media_cache/ - create_update_off_nominal Time: <1ms Result: PASS 332s START /main/media_cache/ - create_update_metadata 332s [test_media_cache.c:create_update_metadata:367]: Got /tmp/test-media-cache-6EcL4G for second file path 332s END /main/media_cache/ - create_update_metadata Time: 1ms Result: PASS 332s START /main/media_cache/ - create_update_nominal 332s [test_media_cache.c:create_update_nominal:236]: Creating resource with /tmp/test-media-cache-bdeEA8 332s [test_media_cache.c:create_update_nominal:241]: Got /tmp/test-media-cache-bdeEA8 for first file path 332s [test_media_cache.c:create_update_nominal:245]: Creating resource with /tmp/test-media-cache-yDlADF 332s [test_media_cache.c:create_update_nominal:250]: Got /tmp/test-media-cache-yDlADF for second file path 332s END /main/media_cache/ - create_update_nominal Time: 3ms Result: PASS 332s START /main/media_cache/ - exists_off_nominal 332s END /main/media_cache/ - exists_off_nominal Time: <1ms Result: PASS 332s START /main/media_cache/ - exists_nominal 332s END /main/media_cache/ - exists_nominal Time: <1ms Result: PASS 332s START /main/netsock2/ - split_hostport 332s END /main/netsock2/ - split_hostport Time: <1ms Result: PASS 332s START /main/netsock2/ - parsing 332s END /main/netsock2/ - parsing Time: <1ms Result: PASS 332s START /main/optional_api/ - test_provide_last 332s END /main/optional_api/ - test_provide_last Time: <1ms Result: PASS 332s START /main/optional_api/ - test_provide_first 332s END /main/optional_api/ - test_provide_first Time: <1ms Result: PASS 332s START /main/pbx/ - test_substitution 332s [test_substitution.c:test_substitution:244]: Testing variable substitution ... 332s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGANI2}' . . . . . passed 332s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTON}' . . . . . passed 332s [test_substitution.c:test_chan_integer:65]: Tested '${CALLINGTNS}' . . . . . passed 332s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${HANGUPCAUSE}' . . . . . passed 332s [test_substitution.c:test_chan_integer_accessor:89]: Tested '${PRIORITY}' . . . . . passed 332s [test_substitution.c:test_chan_string:115]: Tested '${CONTEXT}' . . . . . passed 332s [test_substitution.c:test_chan_string:115]: Tested '${EXTEN}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(language)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(musicclass)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CHANNEL(parkinglot)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CALLERID(name)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CURLOPT(proxyuserpwd)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${CDR(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${ENV(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${GLOBAL(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_variable:144]: Tested '${GROUP()}' . . . . . passed 332s [test_substitution.c:test_2way_function:193]: Tested '${AES_ENCRYPT(abcdefghijklmnop,)}' and '${AES_DECRYPT(abcdefghijklmnop,)}' . . . . . passed 332s [test_substitution.c:test_2way_function:193]: Tested '${BASE64_ENCODE()}' and '${BASE64_DECODE()}' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested '123123' ('${foo}${foo}') == '123123' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A123A123A' ('A${foo}A${foo}A') == 'A123A123A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${bar}}A') == 'A123A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A123A' ('A${${baz}o}A') == 'A123A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A23A' ('A${${baz}o:1}A') == 'A23A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:1}A') == 'A2A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:1:-1}A') == 'A2A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A3A' ('A${${baz}o:-1:1}A') == 'A3A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:1}A') == 'A2A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'A2A' ('A${${baz}o:-2:-1}A') == 'A2A' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'cd&ef' ('${LISTFILTER(list1,&,ab)}') == 'cd&ef' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'ab&ef' ('${LISTFILTER(list1,&,cd)}') == 'ab&ef' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd' ('${LISTFILTER(list1,&,ef)}') == 'ab&cd' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,gh)}') == 'ab&cd&ef' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,c)}') == 'ab&cd&ef' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested 'ab&cd&ef' ('${LISTFILTER(list1,&,d)}') == 'ab&cd&ef' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list2,&,ab)}') == '' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested '' ('${LISTFILTER(list_empty,&,ab)}') == '' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested '123,456' ('${SHELL(printf '%d' 123)},${SHELL(printf '%d' 456)}') == '123,456' . . . . . passed 332s [test_substitution.c:test_expected_result:215]: Tested '123,,456' ('${foo},${CDR(answer)},${SHELL(printf '%d' 456)}') == '123,,456' . . . . . passed 332s [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 332s [test_substitution.c:test_expected_result:215]: Tested '123,,' ('${foo},${this_does_not_exist},${THIS_DOES_NOT_EXIST(either)}') == '123,,' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${BLACKLIST(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${EVAL(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${FIELDNUM(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${FIELDQTY(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${HASHKEYS(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${IMPORT(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${PP_EACH_USER(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${TOLOWER(foo)}' . . . . . passed 332s [test_substitution.c:test_chan_function:168]: Tested '${TOUPPER(foo)}' . . . . . passed 332s END /main/pbx/ - test_substitution Time: 23ms Result: PASS 332s START /main/pbx/ - test_MATH_function 332s [func_math.c:test_MATH_function:682]: Testing MATH() substitution ... 332s END /main/pbx/ - test_MATH_function Time: <1ms Result: PASS 332s START /main/pbx/ - pattern_match_test 332s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the old pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the old pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the old pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 200 to exten _2. in context test_pattern with the new pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern with the new pattern match engine 332s [test_pbx.c:test_exten:183]: Successfully matched 2000 to exten 2000 in context test_pattern_include with the new pattern match engine 332s END /main/pbx/ - pattern_match_test Time: <1ms Result: PASS 332s START /main/pbx/ - variable_substrings 332s END /main/pbx/ - variable_substrings Time: <1ms Result: PASS 332s START /main/poll/ - poll_test 332s [test_poll.c:poll_test:95]: Creating handle that should NEVER block on write 332s [test_poll.c:poll_test:101]: Creating handle that should NEVER block on read 332s [test_poll.c:poll_test:108]: Creating handle that should block on read 332s [test_poll.c:poll_test:168]: Starting thread to ensure we don't block forever 332s [test_poll.c:poll_test:194]: Cancelling failsafe thread. 332s END /main/poll/ - poll_test Time: <1ms Result: PASS 332s START /main/presence/ - channel_presence 332s END /main/presence/ - channel_presence Time: <1ms Result: PASS 332s START /main/sample/ - sample_test 332s [test_skel.c:sample_test:57]: Executing sample test... 332s END /main/sample/ - sample_test Time: <1ms Result: PASS 332s START /main/sched/ - sched_test_freebird 332s [test_sched.c:sched_test_freebird:440]: Received signal, calling Scedule and UNREF 332s [test_sched.c:sched_test_freebird:441]: ID: 1 335s [test_sched.c:sched_test_freebird:448]: Correct number of references '2' 335s END /main/sched/ - sched_test_freebird Time: 3000ms Result: PASS 335s START /main/sched/ - sched_test_order 335s END /main/sched/ - sched_test_order Time: 400ms Result: PASS 335s START /main/sorcery/ - wizard_read_only 335s END /main/sorcery/ - wizard_read_only Time: <1ms Result: PASS 335s START /main/sorcery/ - wizard_observation 335s END /main/sorcery/ - wizard_observation Time: <1ms Result: PASS 335s START /main/sorcery/ - instance_observation 335s END /main/sorcery/ - instance_observation Time: <1ms Result: PASS 335s START /main/sorcery/ - global_observation 335s END /main/sorcery/ - global_observation Time: <1ms Result: PASS 335s START /main/sorcery/ - object_field_registered 335s END /main/sorcery/ - object_field_registered Time: <1ms Result: PASS 335s START /main/sorcery/ - dialplan_function 335s END /main/sorcery/ - dialplan_function Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all 335s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple_all Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard_retrieve_multiple 335s END /main/sorcery/ - configuration_file_wizard_retrieve_multiple Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard_retrieve_field 335s END /main/sorcery/ - configuration_file_wizard_retrieve_field Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard_with_criteria 335s END /main/sorcery/ - configuration_file_wizard_with_criteria Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard_with_file_integrity 335s END /main/sorcery/ - configuration_file_wizard_with_file_integrity Time: <1ms Result: PASS 335s START /main/sorcery/ - configuration_file_wizard 335s END /main/sorcery/ - configuration_file_wizard Time: <1ms Result: PASS 335s START /main/sorcery/ - object_type_observer 335s END /main/sorcery/ - object_type_observer Time: <1ms Result: PASS 335s START /main/sorcery/ - caching_wizard_behavior 335s END /main/sorcery/ - caching_wizard_behavior Time: <1ms Result: PASS 335s START /main/sorcery/ - object_is_stale 335s END /main/sorcery/ - object_is_stale Time: <1ms Result: PASS 335s START /main/sorcery/ - object_delete_uncreated 335s END /main/sorcery/ - object_delete_uncreated Time: <1ms Result: PASS 335s START /main/sorcery/ - object_delete 335s END /main/sorcery/ - object_delete Time: <1ms Result: PASS 335s START /main/sorcery/ - object_update_uncreated 335s END /main/sorcery/ - object_update_uncreated Time: <1ms Result: PASS 335s START /main/sorcery/ - object_update 335s END /main/sorcery/ - object_update Time: <1ms Result: PASS 335s START /main/sorcery/ - object_retrieve_regex 335s END /main/sorcery/ - object_retrieve_regex Time: <1ms Result: PASS 335s START /main/sorcery/ - object_retrieve_multiple_field 335s END /main/sorcery/ - object_retrieve_multiple_field Time: <1ms Result: PASS 335s START /main/sorcery/ - object_retrieve_multiple_all 335s END /main/sorcery/ - object_retrieve_multiple_all Time: <1ms Result: PASS 335s START /main/sorcery/ - object_retrieve_field 335s END /main/sorcery/ - object_retrieve_field Time: <1ms Result: PASS 335s START /main/sorcery/ - object_retrieve_id 335s END /main/sorcery/ - object_retrieve_id Time: <1ms Result: PASS 335s START /main/sorcery/ - object_create 335s END /main/sorcery/ - object_create Time: <1ms Result: PASS 335s START /main/sorcery/ - changeset_create_unchanged 335s END /main/sorcery/ - changeset_create_unchanged Time: <1ms Result: PASS 335s START /main/sorcery/ - changeset_create 335s END /main/sorcery/ - changeset_create Time: <1ms Result: PASS 335s START /main/sorcery/ - extended_fields 335s END /main/sorcery/ - extended_fields Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_apply_fields 335s END /main/sorcery/ - objectset_apply_fields Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_transform 335s END /main/sorcery/ - objectset_transform Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_apply_invalid 335s END /main/sorcery/ - objectset_apply_invalid Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_apply_handler 335s END /main/sorcery/ - objectset_apply_handler Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_apply 335s END /main/sorcery/ - objectset_apply Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_create_regex 335s END /main/sorcery/ - objectset_create_regex Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_json_create 335s END /main/sorcery/ - objectset_json_create Time: <1ms Result: PASS 335s START /main/sorcery/ - objectset_create 335s END /main/sorcery/ - objectset_create Time: <1ms Result: PASS 335s START /main/sorcery/ - object_diff_native 335s END /main/sorcery/ - object_diff_native Time: <1ms Result: PASS 335s START /main/sorcery/ - object_diff 335s END /main/sorcery/ - object_diff Time: <1ms Result: PASS 335s START /main/sorcery/ - object_copy_native 335s END /main/sorcery/ - object_copy_native Time: <1ms Result: PASS 335s START /main/sorcery/ - object_copy 335s END /main/sorcery/ - object_copy Time: <1ms Result: PASS 335s START /main/sorcery/ - object_alloc_without_id 335s END /main/sorcery/ - object_alloc_without_id Time: <1ms Result: PASS 335s START /main/sorcery/ - object_alloc_with_id 335s END /main/sorcery/ - object_alloc_with_id Time: <1ms Result: PASS 335s START /main/sorcery/ - object_fields_register 335s END /main/sorcery/ - object_fields_register Time: <1ms Result: PASS 335s START /main/sorcery/ - object_field_register 335s END /main/sorcery/ - object_field_register Time: <1ms Result: PASS 335s START /main/sorcery/ - object_register_without_mapping 335s END /main/sorcery/ - object_register_without_mapping Time: <1ms Result: PASS 335s START /main/sorcery/ - object_register 335s END /main/sorcery/ - object_register Time: <1ms Result: PASS 335s START /main/sorcery/ - apply_config 335s END /main/sorcery/ - apply_config Time: <1ms Result: PASS 335s START /main/sorcery/ - apply_default 335s END /main/sorcery/ - apply_default Time: <1ms Result: PASS 335s START /main/sorcery/ - open 335s END /main/sorcery/ - open Time: <1ms Result: PASS 335s START /main/sorcery/ - wizard_registration 335s END /main/sorcery/ - wizard_registration Time: <1ms Result: PASS 335s START /main/sorcery/ - wizard_apply_and_insert 335s END /main/sorcery/ - wizard_apply_and_insert Time: <1ms Result: PASS 335s START /main/stdtime/ - time_create_by_unit_str 335s END /main/stdtime/ - time_create_by_unit_str Time: <1ms Result: PASS 335s START /main/stdtime/ - time_create_by_unit 335s END /main/stdtime/ - time_create_by_unit Time: <1ms Result: PASS 335s START /main/stdtime/ - time_str_to_unit 335s END /main/stdtime/ - time_str_to_unit Time: <1ms Result: PASS 335s START /main/stdtime/ - time_tv_to_usec 335s END /main/stdtime/ - time_tv_to_usec Time: <1ms Result: PASS 335s START /main/stdtime/ - timezone_watch 335s [test_time.c:test_timezone_watch:82]: Executing deletion test... 335s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.JkxjeY/test 336s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.JkxjeY/test 336s [test_time.c:test_timezone_watch:82]: Executing symlink test... 336s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.JkxjeY/test 337s [test_time.c:test_timezone_watch:90]: Querying timezone /tmp/timezone.JkxjeY/test 337s END /main/stdtime/ - timezone_watch Time: 2265ms Result: PASS 337s START /main/stream/ - stream_topology_map_create 337s END /main/stream/ - stream_topology_map_create Time: <1ms Result: PASS 337s START /main/stream/ - format_cap_from_stream_topology 337s END /main/stream/ - format_cap_from_stream_topology Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_change_request_from_channel 337s END /main/stream/ - stream_topology_change_request_from_channel Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_change_request_from_application 337s END /main/stream/ - stream_topology_change_request_from_application Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_change_request_from_channel_non_multistream 337s END /main/stream/ - stream_topology_change_request_from_channel_non_multistream Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_change_request_from_application_non_multistream 337s END /main/stream/ - stream_topology_change_request_from_application_non_multistream Time: <1ms Result: PASS 337s START /main/stream/ - stream_read_multistream 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 8 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 1 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: NON-STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 8 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 8 337s [test_stream.c:read_test:1726]: ChanType: MULTI ReadType: STREAM Streams: 4 Frames: 16 Frames per read: 3 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s END /main/stream/ - stream_read_multistream Time: 1ms Result: PASS 337s START /main/stream/ - stream_read_non_multistream 337s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 1 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: NON-STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s [test_stream.c:read_test:1726]: ChanType: NON-MULTI ReadType: STREAM Streams: 2 Frames: 16 Frames per read: 3 Expected Nulls: 0 337s [test_stream.c:read_test:1759]: Frames read: 16 NULL frames: 0 337s END /main/stream/ - stream_read_non_multistream Time: <1ms Result: PASS 337s START /main/stream/ - stream_write_multistream 337s END /main/stream/ - stream_write_multistream Time: <1ms Result: PASS 337s START /main/stream/ - stream_write_non_multistream 337s END /main/stream/ - stream_write_non_multistream Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_channel_set 337s END /main/stream/ - stream_topology_channel_set Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_create_from_channel_nativeformats 337s END /main/stream/ - stream_topology_create_from_channel_nativeformats Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_get_first_stream_by_type 337s END /main/stream/ - stream_topology_get_first_stream_by_type Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_create_from_format_cap 337s END /main/stream/ - stream_topology_create_from_format_cap Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_del_stream 337s END /main/stream/ - stream_topology_del_stream Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_set_stream 337s END /main/stream/ - stream_topology_set_stream Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_append_stream 337s END /main/stream/ - stream_topology_append_stream Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_clone 337s END /main/stream/ - stream_topology_clone Time: <1ms Result: PASS 337s START /main/stream/ - stream_topology_create 337s END /main/stream/ - stream_topology_create Time: <1ms Result: PASS 337s START /main/stream/ - stream_metadata 337s END /main/stream/ - stream_metadata Time: <1ms Result: PASS 337s START /main/stream/ - stream_set_state 337s END /main/stream/ - stream_set_state Time: <1ms Result: PASS 337s START /main/stream/ - stream_set_formats 337s END /main/stream/ - stream_set_formats Time: <1ms Result: PASS 337s START /main/stream/ - stream_set_type 337s END /main/stream/ - stream_set_type Time: <1ms Result: PASS 337s START /main/stream/ - stream_create_no_name 337s END /main/stream/ - stream_create_no_name Time: <1ms Result: PASS 337s START /main/stream/ - stream_create 337s END /main/stream/ - stream_create Time: <1ms Result: PASS 337s START /main/strings/ - in_delimited_string 337s END /main/strings/ - in_delimited_string Time: <1ms Result: PASS 337s START /main/strings/ - temp_strings 337s END /main/strings/ - temp_strings Time: <1ms Result: PASS 337s START /main/strings/ - strings_match 337s END /main/strings/ - strings_match Time: <1ms Result: PASS 337s START /main/strings/ - escape 337s END /main/strings/ - escape Time: <1ms Result: PASS 337s START /main/strings/ - escape_semicolons 337s END /main/strings/ - escape_semicolons Time: <1ms Result: PASS 337s START /main/strings/ - strsep_quoted 337s END /main/strings/ - strsep_quoted Time: <1ms Result: PASS 337s START /main/strings/ - strsep 337s END /main/strings/ - strsep Time: <1ms Result: PASS 337s START /main/strings/ - ends_with 337s END /main/strings/ - ends_with Time: <1ms Result: PASS 337s START /main/strings/ - begins_with 337s END /main/strings/ - begins_with Time: <1ms Result: PASS 337s START /main/strings/ - str_test 337s END /main/strings/ - str_test Time: <1ms Result: PASS 337s START /main/taskprocessor/ - serializer_pool 341s END /main/taskprocessor/ - serializer_pool Time: 4001ms Result: PASS 341s START /main/taskprocessor/ - taskprocessor_push_local 341s END /main/taskprocessor/ - taskprocessor_push_local Time: 1ms Result: PASS 341s START /main/taskprocessor/ - taskprocessor_shutdown 341s END /main/taskprocessor/ - taskprocessor_shutdown Time: <1ms Result: PASS 341s START /main/taskprocessor/ - taskprocessor_listener 341s END /main/taskprocessor/ - taskprocessor_listener Time: <1ms Result: PASS 341s START /main/taskprocessor/ - subsystem_alert 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 1 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 2 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 3 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 4 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 5 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 6 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 7 341s [test_taskprocessor.c:subsystem_alert:237]: Subsystem alert triggered correctly at 6 341s [test_taskprocessor.c:subsystem_alert:240]: Global alert triggered correctly at 6 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 8 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 9 341s [test_taskprocessor.c:subsystem_alert:224]: Pushing task 10 341s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 1 342s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 2 342s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 3 343s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 4 343s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 5 344s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 6 344s [test_taskprocessor.c:subsystem_alert:279]: Subsystem alert cleared correctly at 3 344s [test_taskprocessor.c:subsystem_alert:282]: Global alert cleared correctly at 3 344s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 7 345s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 8 345s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 9 346s [test_taskprocessor.c:subsystem_alert:266]: Waiting on task 10 346s END /main/taskprocessor/ - subsystem_alert Time: 5001ms Result: PASS 346s START /main/taskprocessor/ - default_taskprocessor_load 346s END /main/taskprocessor/ - default_taskprocessor_load Time: 49ms Result: PASS 346s START /main/taskprocessor/ - default_taskprocessor 346s END /main/taskprocessor/ - default_taskprocessor Time: <1ms Result: PASS 346s START /main/test/ - registrations 346s END /main/test/ - registrations Time: <1ms Result: PASS 346s START /main/test_capture/ - test_capture_false 346s [test_capture.c:test_capture_false:120]: Executing false exit test... 346s END /main/test_capture/ - test_capture_false Time: 9ms Result: PASS 346s START /main/test_capture/ - test_capture_true 346s [test_capture.c:test_capture_true:61]: Executing true exit test... 346s END /main/test_capture/ - test_capture_true Time: 8ms Result: PASS 346s START /main/test_capture/ - test_capture_stdout_stderr 346s [test_capture.c:test_capture_stdout_stderr:318]: Executing stdout/stderr test... 346s END /main/test_capture/ - test_capture_stdout_stderr Time: 7ms Result: PASS 346s START /main/test_capture/ - test_capture_with_dynamic 346s [test_capture.c:test_capture_with_dynamic:249]: Executing dynamic argument test... 346s END /main/test_capture/ - test_capture_with_dynamic Time: 8ms Result: PASS 346s START /main/test_capture/ - test_capture_with_stdin 346s [test_capture.c:test_capture_with_stdin:183]: Executing stdin test... 346s END /main/test_capture/ - test_capture_with_stdin Time: 8ms Result: PASS 346s START /main/threadpool/ - threadpool_serializer_dupe 346s END /main/threadpool/ - threadpool_serializer_dupe Time: <1ms Result: PASS 346s START /main/threadpool/ - threadpool_serializer 347s END /main/threadpool/ - threadpool_serializer Time: 1000ms Result: PASS 347s START /main/threadpool/ - more_destruction 347s END /main/threadpool/ - more_destruction Time: <1ms Result: PASS 347s START /main/threadpool/ - task_distribution 347s END /main/threadpool/ - task_distribution Time: <1ms Result: PASS 347s START /main/threadpool/ - reactivation 347s END /main/threadpool/ - reactivation Time: <1ms Result: PASS 347s START /main/threadpool/ - max_size 347s END /main/threadpool/ - max_size Time: <1ms Result: PASS 347s START /main/threadpool/ - auto_increment 347s END /main/threadpool/ - auto_increment Time: <1ms Result: PASS 348s START /main/threadpool/ - one_thread_multiple_tasks 348s END /main/threadpool/ - one_thread_multiple_tasks Time: <1ms Result: PASS 348s START /main/threadpool/ - one_thread_one_task 348s END /main/threadpool/ - one_thread_one_task Time: <1ms Result: PASS 348s START /main/threadpool/ - one_task_one_thread 348s END /main/threadpool/ - one_task_one_thread Time: <1ms Result: PASS 348s START /main/threadpool/ - thread_timeout_thrash 378s END /main/threadpool/ - thread_timeout_thrash Time: 31013ms Result: PASS 378s START /main/threadpool/ - thread_timeout 380s END /main/threadpool/ - thread_timeout Time: 2000ms Result: PASS 380s START /main/threadpool/ - thread_destruction 380s END /main/threadpool/ - thread_destruction Time: <1ms Result: PASS 380s START /main/threadpool/ - thread_creation 380s END /main/threadpool/ - thread_creation Time: <1ms Result: PASS 380s START /main/threadpool/ - initial_threads 380s END /main/threadpool/ - initial_threads Time: <1ms Result: PASS 380s START /main/threadpool/ - push 380s END /main/threadpool/ - push Time: <1ms Result: PASS 381s START /main/uri/ - uri_default_http_secure 381s END /main/uri/ - uri_default_http_secure Time: <1ms Result: PASS 381s START /main/uri/ - uri_default_http 381s END /main/uri/ - uri_default_http Time: <1ms Result: PASS 381s START /main/uri/ - uri_parse 381s END /main/uri/ - uri_parse Time: <1ms Result: PASS 381s START /main/utf8/ - replace_invalid 381s END /main/utf8/ - replace_invalid Time: <1ms Result: PASS 381s START /main/utf8/ - utf8_validator 381s END /main/utf8/ - utf8_validator Time: <1ms Result: PASS 381s START /main/utf8/ - copy_string 381s END /main/utf8/ - copy_string Time: <1ms Result: PASS 381s START /main/utf8/ - is_valid 381s END /main/utf8/ - is_valid Time: <1ms Result: PASS 381s START /main/utils/ - string_field_aggregate_test 381s [test_stringfields.c:string_field_aggregate_test:392]: Structures 3 embedded pool initialized successfully. 381s [test_stringfields.c:string_field_aggregate_test:410]: Structures 3 additional pool initialized successfully. 381s [test_stringfields.c:string_field_aggregate_test:422]: Structures 1/2 are equal as expected. 381s [test_stringfields.c:string_field_aggregate_test:430]: Structures 1/3 are different as expected. 381s [test_stringfields.c:string_field_aggregate_test:438]: Structures 2/3 are different as expected. 381s [test_stringfields.c:string_field_aggregate_test:446]: Structures 3/4 are different as expected. 381s [test_stringfields.c:string_field_aggregate_test:454]: Copying from structure 3 to structure 1 succeeded! 381s [test_stringfields.c:string_field_aggregate_test:463]: Structures 1/3 are equal as expected. 381s [test_stringfields.c:string_field_aggregate_test:470]: Structures 1/2 are different as expected. 381s [test_stringfields.c:string_field_aggregate_test:473]: Reset but don't free. 381s [test_stringfields.c:string_field_aggregate_test:484]: Structures 1/2 are the same (empty) as expected. 381s [test_stringfields.c:string_field_aggregate_test:492]: Structure 4 embedded pool is the current pool as expected. 381s [test_stringfields.c:string_field_aggregate_test:500]: Structure 4 embedded pool does not have a previous as expected. 381s END /main/utils/ - string_field_aggregate_test Time: <1ms Result: PASS 381s START /main/utils/ - string_field_test 381s [test_stringfields.c:string_field_test:79]: First things first. Let's see if we can actually allocate string fields 381s [test_stringfields.c:string_field_test:85]: All right! Successfully allocated! Now let's get down to business 381s [test_stringfields.c:string_field_test:89]: We're going to set some string fields and perform some checks 381s [test_stringfields.c:string_field_test:94]: First we're going to make sure that the strings are actually set to what we expect 381s [test_stringfields.c:string_field_test:100]: test_struct.string1 appears to be all clear. It has 'elephant' and that's what we expect 381s [test_stringfields.c:string_field_test:107]: test_struct.string2 appears to be all clear. It has 'hippopotamus' and that's what we expect 381s [test_stringfields.c:string_field_test:110]: Now let's make sure that our recorded capacities for these strings is what we expect 381s [test_stringfields.c:string_field_test:117]: string1 has the allocation area we expect: 9 381s [test_stringfields.c:string_field_test:125]: string2 has the allocation area we expect: 13 381s [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 381s [test_stringfields.c:string_field_test:137]: string1 successfully was changed to 'rhino' 381s [test_stringfields.c:string_field_test:144]: Shrinking string1 allowed it to stay in the same place in memory 381s [test_stringfields.c:string_field_test:151]: Shrinking string1 did not change its allocation area (This is a good thing) 381s [test_stringfields.c:string_field_test:154]: Next, let's increase it a little but not all the way to its original size 381s [test_stringfields.c:string_field_test:163]: string1 successfully was changed to 'mammoth' 381s [test_stringfields.c:string_field_test:170]: Expanding string1 allowed it to stay in the same place in memory 381s [test_stringfields.c:string_field_test:177]: Expanding string1 did not change its allocation area (This is a good thing) 381s [test_stringfields.c:string_field_test:180]: Cool, now let's bring it back to its original size and see what happens 381s [test_stringfields.c:string_field_test:188]: string1 successfully changed to 'elephant' 381s [test_stringfields.c:string_field_test:195]: Restoring string1 did not cause it to move (This is a good thing) 381s [test_stringfields.c:string_field_test:202]: The allocation amount for string1 is still holding steady 381s [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 381s [test_stringfields.c:string_field_test:214]: string2 successfully changed to 'hippopotamus face' 381s [test_stringfields.c:string_field_test:222]: The allocation amount successfully increased for string2 when it grew 381s [test_stringfields.c:string_field_test:229]: string2 stayed in place when it grew. Good job! 381s [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 381s [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' 381s [test_stringfields.c:string_field_test:248]: Good. Setting string1 to a long value caused it to change addresses 381s [test_stringfields.c:string_field_test:256]: The stored allocation size of string1 is what we expect 381s [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 381s [test_stringfields.c:string_field_test:281]: Three different pools are linked as expected. 381s [test_stringfields.c:string_field_test:289]: After removing a pool the remaining two are linked as expected. 381s END /main/utils/ - string_field_test Time: <1ms Result: PASS 381s START /main/utils/ - quote_unescaping 381s END /main/utils/ - quote_unescaping Time: <1ms Result: PASS 381s START /main/utils/ - quote_mutation 381s END /main/utils/ - quote_mutation Time: <1ms Result: PASS 381s START /main/utils/ - crypt_test 381s END /main/utils/ - crypt_test Time: 15ms Result: PASS 381s START /main/utils/ - safe_mkdir_test 381s END /main/utils/ - safe_mkdir_test Time: 1ms Result: PASS 381s START /main/utils/ - base64_test 381s END /main/utils/ - base64_test Time: <1ms Result: PASS 381s START /main/utils/ - sha1_test 381s [test_utils.c:sha1_test:250]: Testing SHA1 ... 381s END /main/utils/ - sha1_test Time: <1ms Result: PASS 381s START /main/utils/ - md5_test 381s [test_utils.c:md5_test:205]: Testing MD5 ... 381s END /main/utils/ - md5_test Time: <1ms Result: PASS 381s START /main/utils/ - quoted_escape_test 381s END /main/utils/ - quoted_escape_test Time: <1ms Result: PASS 381s START /main/utils/ - uri_encode_decode_test 381s END /main/utils/ - uri_encode_decode_test Time: <1ms Result: PASS 381s START /main/uuid/ - uuid 381s [test_uuid.c:uuid:59]: Generate UUID direct to string, got 7193af89-c377-4665-91ed-37c9b937543a 381s [test_uuid.c:uuid:90]: Second generated UUID converted to string, got ed1d2275-1490-4a2a-aa8e-65d3fb2184ca 381s END /main/uuid/ - uuid Time: <1ms Result: PASS 381s START /main/vector/ - basic 381s END /main/vector/ - basic Time: <1ms Result: PASS 381s START /main/vector/ - basic_integer 381s END /main/vector/ - basic_integer Time: <1ms Result: PASS 381s START /main/vector/ - callbacks 381s END /main/vector/ - callbacks Time: <1ms Result: PASS 381s START /main/vector/ - locks 381s END /main/vector/ - locks Time: <1ms Result: PASS 381s START /main/voicemail_api/ - off_nominal_msg_playback 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_1234/Old with ID 1736845610-909401725 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_1234/INBOX with ID 1736845610-960311778 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_2345/INBOX with ID 1736845610-1500739833 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1493]: Created message in test_vm_api_2345/INBOX with ID 1736845610-719848782 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1502]: Playing back message from invalid mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1505]: Playing back message from NULL mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1508]: Playing back message from invalid context 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1511]: Playing back message from invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1514]: Playing back message from NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1517]: Playing back message with invalid message specifier 381s [test_voicemail_api.c:voicemail_api_off_nominal_msg_playback:1520]: Playing back message with NULL message specifier 381s END /main/voicemail_api/ - off_nominal_msg_playback Time: 10ms Result: PASS 381s START /main/voicemail_api/ - nominal_msg_playback 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_1234/Old with ID 1736845610-909401725 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_1234/INBOX with ID 1736845610-960311778 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_2345/INBOX with ID 1736845610-1500739833 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1431]: Created message in test_vm_api_2345/INBOX with ID 1736845610-719848782 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1443]: Playing back message from test_vm_api_1234 to mock channel 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1446]: Playing back message from test_vm_api_2345 to callback function 381s [test_voicemail_api.c:voicemail_api_nominal_msg_playback:1451]: Playing back message from test_vm_api_2345 to callback function with default context 381s END /main/voicemail_api/ - nominal_msg_playback Time: 452ms Result: PASS 381s START /main/voicemail_api/ - off_nominal_forward 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1353]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1362]: Test forwarding from an invalid mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1365]: Test forwarding from a NULL mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1368]: Test forwarding from an invalid context 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1371]: Test forwarding from an invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1374]: Test forwarding from a NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1377]: Test forwarding to an invalid mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1380]: Test forwarding to a NULL mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1383]: Test forwarding to an invalid context 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1386]: Test forwarding to an invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1390]: Test forwarding to a NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1393]: Test forwarding when no messages are select 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1396]: Test forwarding a message that doesn't exist 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1400]: Test forwarding multiple messages, where some messages don't exist 381s [test_voicemail_api.c:voicemail_api_off_nominal_forward:1403]: Test forwarding a message with an invalid size specifier 381s END /main/voicemail_api/ - off_nominal_forward Time: 8ms Result: PASS 381s START /main/voicemail_api/ - nominal_forward 381s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_nominal_forward:1237]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [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 381s [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 381s [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 381s [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 381s [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 381s END /main/voicemail_api/ - nominal_forward Time: 24ms Result: PASS 381s START /main/voicemail_api/ - off_nominal_remove 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1178]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1184]: Test removing a single message with an invalid mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1187]: Test removing a single message with a NULL mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1190]: Test removing a single message with an invalid context 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1193]: Test removing a single message with an invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1196]: Test removing a single message with a NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1199]: Test removing a single message with an invalid message number 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1203]: Test removing multiple messages with a single invalid message number 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1207]: Test removing no messages with no message numbers 381s [test_voicemail_api.c:voicemail_api_off_nominal_remove:1210]: Test removing multiple messages with an invalid size specifier 381s END /main/voicemail_api/ - off_nominal_remove Time: 7ms Result: PASS 381s START /main/voicemail_api/ - nominal_remove 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1131]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1139]: Test removing a single message from INBOX 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1142]: Test removing a single message from Old 381s [test_voicemail_api.c:voicemail_api_nominal_remove:1145]: Test removing multiple messages from INBOX 381s END /main/voicemail_api/ - nominal_remove Time: 9ms Result: PASS 381s START /main/voicemail_api/ - off_nominal_move 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1059]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1068]: Test move attempt for invalid mailbox test_vm_3456 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1073]: Test move attempt for invalid context test_vm_api_defunct 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1076]: Test move attempt to invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1079]: Test move attempt from invalid folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1082]: Test move attempt to NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1085]: Test move attempt from NULL folder 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1088]: Test move attempt with non-existent message number 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1092]: Test move attempt with invalid message number 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1096]: Test move attempt with 0 number of messages 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1100]: Test move attempt with invalid number of messages 381s [test_voicemail_api.c:voicemail_api_off_nominal_move:1103]: Test move attempt with non-existent multiple messages, where some messages exist 381s END /main/voicemail_api/ - off_nominal_move Time: 8ms Result: PASS 381s START /main/voicemail_api/ - nominal_move 381s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_nominal_move:985]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_nominal_move:992]: Test move of test_vm_api_1234 message from INBOX to Family 381s [test_voicemail_api.c:voicemail_api_nominal_move:995]: Test move of test_vm_api_1234 message from Old to Family 381s [test_voicemail_api.c:voicemail_api_nominal_move:1009]: Test move of test_vm_api_2345 messages from Inbox to Family 381s [test_voicemail_api.c:voicemail_api_nominal_move:1020]: Test move of test_vm_api_2345 message from Family to INBOX 381s END /main/voicemail_api/ - nominal_move Time: 12ms Result: PASS 381s START /main/voicemail_api/ - off_nominal_snapshot 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:945]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:947]: Test access to non-existent mailbox test_vm_api_3456 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:950]: Test access to null mailbox 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:953]: Test access non-existent context test_vm_api_defunct 381s [test_voicemail_api.c:voicemail_api_off_nominal_snapshot:956]: Test non-existent folder test_vm_api_platypus 381s END /main/voicemail_api/ - off_nominal_snapshot Time: 7ms Result: PASS 381s START /main/voicemail_api/ - nominal_snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_1234/Old with ID 1736845611-909401725 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_1234/INBOX with ID 1736845611-960311778 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_2345/INBOX with ID 1736845611-1500739833 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:854]: Created message in test_vm_api_2345/INBOX with ID 1736845611-719848782 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:856]: Test retrieving message 1 from INBOX of test_vm_1234 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:859]: Found message 1736845611-960311778 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:862]: Test retrieving message 0 from Old of test_vm_1234 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:865]: Found message 1736845611-909401725 in snapshot 381s [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 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:871]: Found message 1736845611-909401725 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:872]: Found message 1736845611-960311778 in snapshot 381s [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 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:878]: Found message 1736845611-960311778 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:879]: Found message 1736845611-909401725 in snapshot 381s [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 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:885]: Found message 1736845611-960311778 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:886]: Found message 1736845611-909401725 in snapshot 381s [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 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:892]: Found message 1736845611-909401725 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:893]: Found message 1736845611-960311778 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:896]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by id 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:899]: Found message 1736845611-909401725 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:900]: Found message 1736845611-960311778 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:903]: Test retrieving message 0, 1 from all folders of test_vm_1234 ordered by time 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:906]: Found message 1736845611-909401725 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:907]: Found message 1736845611-960311778 in snapshot 381s [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 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:913]: Found message 1736845611-909401725 in snapshot 381s [test_voicemail_api.c:voicemail_api_nominal_snapshot:914]: Found message 1736845611-960311778 in snapshot 381s END /main/voicemail_api/ - nominal_snapshot Time: 16ms Result: PASS 381s START /main/xml_escape/ - xml_escape_test 381s END /main/xml_escape/ - xml_escape_test Time: <1ms Result: PASS 381s START /mwi/ - explicit_publish 381s END /mwi/ - explicit_publish Time: 46ms Result: PASS 381s START /mwi/ - implicit_publish 381s END /mwi/ - implicit_publish Time: 44ms Result: PASS 381s START /res/adsi/ - adsi_loaded_test 381s END /res/adsi/ - adsi_loaded_test Time: <1ms Result: PASS 381s START /res/aeap/ - send_msg_handle_request 381s END /res/aeap/ - send_msg_handle_request Time: 1ms Result: PASS 381s START /res/aeap/ - send_msg_handle_response 381s END /res/aeap/ - send_msg_handle_response Time: <1ms Result: PASS 381s START /res/aeap/ - send_msg_handle_string 383s END /res/aeap/ - send_msg_handle_string Time: 1999ms Result: PASS 383s START /res/aeap/ - create_and_connect 383s END /res/aeap/ - create_and_connect Time: <1ms Result: PASS 383s START /res/aeap/speech/ - res_speech_aeap_test 383s END /res/aeap/speech/ - res_speech_aeap_test Time: 1ms Result: PASS 383s START /res/aeap/transaction/ - transaction_exec_timeout 383s END /res/aeap/transaction/ - transaction_exec_timeout Time: 99ms Result: PASS 383s START /res/aeap/transaction/ - transaction_exec 384s END /res/aeap/transaction/ - transaction_exec Time: 1000ms Result: PASS 384s START /res/aeap/transport/ - transport_create_invalid 384s END /res/aeap/transport/ - transport_create_invalid Time: <1ms Result: PASS 384s START /res/aeap/transport/ - transport_create 384s END /res/aeap/transport/ - transport_create Time: <1ms Result: PASS 384s START /res/aeap/transport/ - transport_connect 384s END /res/aeap/transport/ - transport_connect Time: <1ms Result: PASS 384s START /res/aeap/transport/ - transport_connect_fail 384s END /res/aeap/transport/ - transport_connect_fail Time: <1ms Result: PASS 384s START /res/aeap/transport/ - transport_binary 384s END /res/aeap/transport/ - transport_binary Time: 1ms Result: PASS 384s START /res/aeap/transport/ - transport_string 384s END /res/aeap/transport/ - transport_string Time: <1ms Result: PASS 384s START /res/agi/ - agi_loaded_test 384s END /res/agi/ - agi_loaded_test Time: 1ms Result: PASS 384s START /res/agi/ - null_agi_docs 384s END /res/agi/ - null_agi_docs Time: <1ms Result: PASS 384s START /res/ari/ - invoke_not_found 384s END /res/ari/ - invoke_not_found Time: <1ms Result: PASS 384s START /res/ari/ - invoke_bad_post 384s END /res/ari/ - invoke_bad_post Time: <1ms Result: PASS 384s START /res/ari/ - invoke_post 384s END /res/ari/ - invoke_post Time: <1ms Result: PASS 384s START /res/ari/ - invoke_delete 384s END /res/ari/ - invoke_delete Time: <1ms Result: PASS 384s START /res/ari/ - invoke_wildcard 384s END /res/ari/ - invoke_wildcard Time: <1ms Result: PASS 384s START /res/ari/ - invoke_get 384s END /res/ari/ - invoke_get Time: <1ms Result: PASS 384s START /res/ari/ - get_docs_hackerz 384s END /res/ari/ - get_docs_hackerz Time: <1ms Result: PASS 384s START /res/ari/ - get_docs_notfound 384s END /res/ari/ - get_docs_notfound Time: <1ms Result: PASS 384s START /res/ari/ - get_docs_nohost 384s END /res/ari/ - get_docs_nohost Time: <1ms Result: PASS 384s START /res/ari/ - get_docs 384s END /res/ari/ - get_docs Time: <1ms Result: PASS 384s START /res/crypto/ - crypto_loaded_test 384s END /res/crypto/ - crypto_loaded_test Time: <1ms Result: PASS 384s START /res/http_media_cache/ - retrieve_content_type 384s END /res/http_media_cache/ - retrieve_content_type Time: 3ms Result: PASS 384s START /res/http_media_cache/ - retrieve_parsed_uri 384s END /res/http_media_cache/ - retrieve_parsed_uri Time: <1ms Result: PASS 384s START /res/http_media_cache/ - retrieve_cache_control_directives 384s [test_http_media_cache.c:retrieve_cache_control_directives:322]: Testing no-cache... 384s [test_http_media_cache.c:retrieve_cache_control_directives:329]: Testing no-cache with ETag... 384s [test_http_media_cache.c:retrieve_cache_control_directives:339]: Testing no-cache with max-age... 384s [test_http_media_cache.c:retrieve_cache_control_directives:344]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_directives:351]: Testing must-revalidate... 384s [test_http_media_cache.c:retrieve_cache_control_directives:358]: Testing must-revalidate with ETag... 384s [test_http_media_cache.c:retrieve_cache_control_directives:368]: Testing must-revalidate with max-age... 384s [test_http_media_cache.c:retrieve_cache_control_directives:373]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s END /res/http_media_cache/ - retrieve_cache_control_directives Time: 4ms Result: PASS 384s START /res/http_media_cache/ - retrieve_cache_control_age 384s [test_http_media_cache.c:retrieve_cache_control_age:406]: Testing max-age... 384s [test_http_media_cache.c:retrieve_cache_control_age:410]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_age:414]: Testing s-maxage... 384s [test_http_media_cache.c:retrieve_cache_control_age:420]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_age:424]: Testing max-age and s-maxage... 384s [test_http_media_cache.c:retrieve_cache_control_age:430]: Checking 1736846217 >= 1736846214 and 1736846211 <= 1736846214 384s [test_http_media_cache.c:retrieve_cache_control_age:434]: Testing max-age and Expires... 384s [test_http_media_cache.c:retrieve_cache_control_age:441]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_age:445]: Testing s-maxage and Expires... 384s [test_http_media_cache.c:retrieve_cache_control_age:452]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_age:456]: Testing s-maxage and Expires... 384s [test_http_media_cache.c:retrieve_cache_control_age:463]: Checking 1736845917 >= 1736845914 and 1736845911 <= 1736845914 384s [test_http_media_cache.c:retrieve_cache_control_age:467]: Testing max-age, s-maxage, and Expires... 384s [test_http_media_cache.c:retrieve_cache_control_age:474]: Checking 1736846217 >= 1736846214 and 1736846211 <= 1736846214 384s END /res/http_media_cache/ - retrieve_cache_control_age Time: 10ms Result: PASS 384s START /res/http_media_cache/ - retrieve_etag_expired 384s [test_http_media_cache.c:retrieve_etag_expired:514]: Checking 1736845616 >= 1736845613 and 1736845610 <= 1736845613 384s END /res/http_media_cache/ - retrieve_etag_expired Time: <1ms Result: PASS 384s START /res/http_media_cache/ - retrieve_expires 384s [test_http_media_cache.c:retrieve_expires:554]: Checking 1736848617 >= 1736848614 and 1736848611 <= 1736848614 384s [test_http_media_cache.c:retrieve_expires:564]: Checking 1736845616 >= 1736845613 and 1736845610 <= 1736845613 384s END /res/http_media_cache/ - retrieve_expires Time: 1ms Result: PASS 384s START /res/http_media_cache/ - retrieve_etag 384s [test_http_media_cache.c:retrieve_etag:604]: Checking 1736845617 >= 1736845614 and 1736845611 <= 1736845614 384s END /res/http_media_cache/ - retrieve_etag Time: 1ms Result: PASS 384s START /res/http_media_cache/ - retrieve_nominal 384s [test_http_media_cache.c:retrieve_nominal:642]: Checking 1736845617 >= 1736845614 and 1736845611 <= 1736845614 384s END /res/http_media_cache/ - retrieve_nominal Time: <1ms Result: PASS 384s START /res/http_media_cache/ - create_nominal 384s [test_http_media_cache.c:create_nominal:675]: Checking 1736845617 >= 1736845614 and 1736845611 <= 1736845614 384s END /res/http_media_cache/ - create_nominal Time: <1ms Result: PASS 384s START /res/parking/ - dynamic_parking_variables 384s [parking/parking_tests.c:dynamic_parking_variables:756]: Creating expected configuration for dynamic parking lot 384s [parking/parking_tests.c:dynamic_parking_variables:775]: Creating template lot 384s [parking/parking_tests.c:dynamic_parking_variables:784]: Creating Alice channel to test dynamic parking lot creation. 384s [parking/parking_tests.c:dynamic_parking_variables:794]: Setting Dynamic Parking channel variables on Alice. 384s [parking/parking_tests.c:dynamic_parking_variables:802]: Generating dynamic parking lot based on Alice's channel variables. 384s [parking/parking_tests.c:dynamic_parking_variables:819]: Dynamic parking lot created successfully and matches expectations. Test passed. 384s END /res/parking/ - dynamic_parking_variables Time: 1ms Result: PASS 384s START /res/parking/ - extension_conflicts 384s [parking/parking_tests.c:extension_conflicts:597]: Creating the base lot. This should pass. 384s [parking/parking_tests.c:extension_conflicts:607]: Creating a test lot which will overlap. 384s [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. 384s [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. 384s [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. 384s [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. 384s END /res/parking/ - extension_conflicts Time: <1ms Result: PASS 384s START /res/parking/ - park_extensions 384s [parking/parking_tests.c:park_extensions:551]: Extensions for the test parking lot were verified. Cleaning up and verifying their removal. 384s [parking/parking_tests.c:park_extensions:565]: Extensions for the test parking lot verified as removed. Test completed successfully. 384s END /res/parking/ - park_extensions Time: <1ms Result: PASS 384s START /res/parking/ - park_retrieve 384s [parking/parking_tests.c:retrieve_call:405]: Creating test parking lot 'unit_tests_res_parking_test_lot' 385s [parking/parking_tests.c:retrieve_call:446]: Successfully retrieved parked user from the parking lot. Validating user data. 385s END /res/parking/ - park_retrieve Time: 1000ms Result: PASS 385s START /res/parking/ - park_channel 385s [parking/parking_tests.c:park_call:254]: Creating test parking lot 'unit_tests_res_parking_test_lot' 386s END /res/parking/ - park_channel Time: 1000ms Result: PASS 386s START /res/parking/ - create_lot 386s [parking/parking_tests.c:create_lot:206]: Creating test parking lot 'unit_tests_res_parking_test_lot' 386s [parking/parking_tests.c:create_lot:214]: Successfully created parking lot. Retrieving test parking lot from container. 386s [parking/parking_tests.c:create_lot:223]: Successfully retrieved parking lot. Removing test parking lot from container. 386s [parking/parking_tests.c:create_lot:229]: Parking lot was successfully removed from the container. Test complete. 386s END /res/parking/ - create_lot Time: <1ms Result: PASS 386s START /res/prometheus/ - bridge_to_string 386s [test_res_prometheus.c:bridge_to_string:760]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 386s # TYPE asterisk_channels_count gauge 386s asterisk_channels_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_sum Total call count. 386s # TYPE asterisk_calls_sum counter 386s asterisk_calls_sum{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_count Current call count. 386s # TYPE asterisk_calls_count gauge 386s asterisk_calls_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_endpoints_count Current endpoint count. 386s # TYPE asterisk_endpoints_count gauge 386s asterisk_endpoints_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_bridges_count Current bridge count. 386s # TYPE asterisk_bridges_count gauge 386s asterisk_bridges_count{eid="fa:16:3e:78:8c:d1"} 3 386s # HELP asterisk_bridges_channels_count Number of channels in the bridge. 386s # TYPE asterisk_bridges_channels_count gauge 386s asterisk_bridges_channels_count{eid="fa:16:3e:78:8c:d1",id="e499fd38-18d2-44ea-85f0-738ae2685a09",tech="simple_bridge",subclass="basic",creator="",name=""} 0 386s asterisk_bridges_channels_count{eid="fa:16:3e:78:8c:d1",id="f52c8d4c-4d4b-46b2-aa7e-0b450075e4f6",tech="simple_bridge",subclass="basic",creator="",name=""} 0 386s 386s END /res/prometheus/ - bridge_to_string Time: <1ms Result: PASS 386s START /res/prometheus/ - config_general_core_metrics 386s [test_res_prometheus.c:config_general_core_metrics:680]: -> CURLing request... 386s [test_res_prometheus.c:config_general_core_metrics:688]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 386s # TYPE asterisk_channels_count gauge 386s asterisk_channels_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_sum Total call count. 386s # TYPE asterisk_calls_sum counter 386s asterisk_calls_sum{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_count Current call count. 386s # TYPE asterisk_calls_count gauge 386s asterisk_calls_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_endpoints_count Current endpoint count. 386s # TYPE asterisk_endpoints_count gauge 386s asterisk_endpoints_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_bridges_count Current bridge count. 386s # TYPE asterisk_bridges_count gauge 386s asterisk_bridges_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_core_properties Asterisk instance properties. The value of this will always be 1. 386s # TYPE asterisk_core_properties counter 386s asterisk_core_properties{eid="fa:16:3e:78:8c:d1",version="22.1.0~dfsg+~cs6.14.60671435-1",build_options="OPTIONAL_API, TEST_FRAMEWORK",build_date="2024-11-27 11:37:42 UTC",build_os="Linux",build_kernel="unknown",build_host="buildd.debian.org"} 1 386s # HELP asterisk_core_uptime_seconds Asterisk instance uptime in seconds. 386s # TYPE asterisk_core_uptime_seconds counter 386s asterisk_core_uptime_seconds{eid="fa:16:3e:78:8c:d1"} 182 386s # HELP asterisk_core_last_reload_seconds Time since last Asterisk reload in seconds. 386s # TYPE asterisk_core_last_reload_seconds counter 386s asterisk_core_last_reload_seconds{eid="fa:16:3e:78:8c:d1"} 182 386s # HELP asterisk_core_scrape_time_ms Total time taken to collect metrics, in milliseconds 386s # TYPE asterisk_core_scrape_time_ms counter 386s asterisk_core_scrape_time_ms{eid="fa:16:3e:78:8c:d1"} 0 386s 386s [test_res_prometheus.c:config_general_core_metrics:690]: -> Checking for core properties 386s [test_res_prometheus.c:config_general_core_metrics:693]: -> Checking for uptime 386s [test_res_prometheus.c:config_general_core_metrics:696]: -> Checking for last reload 386s [test_res_prometheus.c:config_general_core_metrics:699]: -> Checking for scrape time 386s END /res/prometheus/ - config_general_core_metrics Time: <1ms Result: PASS 386s START /res/prometheus/ - config_general_basic_auth 386s [test_res_prometheus.c:config_general_basic_auth:555]: Testing without auth credentials 386s [test_res_prometheus.c:config_general_basic_auth:556]: -> CURLing request... 386s [test_res_prometheus.c:config_general_basic_auth:563]: -> CURL returned 401 386s [test_res_prometheus.c:config_general_basic_auth:566]: Testing with invalid auth credentials 386s [test_res_prometheus.c:config_general_basic_auth:567]: -> CURLing request... 386s [test_res_prometheus.c:config_general_basic_auth:576]: -> CURL returned 401 386s [test_res_prometheus.c:config_general_basic_auth:579]: Testing with valid auth credentials 386s [test_res_prometheus.c:config_general_basic_auth:580]: -> CURLing request... 386s [test_res_prometheus.c:config_general_basic_auth:588]: -> CURL returned 200 386s END /res/prometheus/ - config_general_basic_auth Time: <1ms Result: PASS 386s START /res/prometheus/ - config_general_enabled 386s [test_res_prometheus.c:config_general_enabled:628]: -> CURLing request... 386s [test_res_prometheus.c:config_general_enabled:635]: -> CURL returned 503 386s END /res/prometheus/ - config_general_enabled Time: <1ms Result: PASS 386s START /res/prometheus/ - gauge_create 386s END /res/prometheus/ - gauge_create Time: <1ms Result: PASS 386s START /res/prometheus/ - gauge_to_string 386s END /res/prometheus/ - gauge_to_string Time: <1ms Result: PASS 386s START /res/prometheus/ - counter_create 386s END /res/prometheus/ - counter_create Time: <1ms Result: PASS 386s START /res/prometheus/ - counter_to_string 386s END /res/prometheus/ - counter_to_string Time: <1ms Result: PASS 386s START /res/prometheus/ - metric_register 386s [test_res_prometheus.c:metric_register:291]: Testing nominal registration 386s [test_res_prometheus.c:metric_register:292]: -> Static metric 386s [test_res_prometheus.c:metric_register:294]: -> Malloc'd metric 386s [test_res_prometheus.c:metric_register:300]: Testing nominal registration of child metrics 386s [test_res_prometheus.c:metric_register:315]: Testing name collisions 386s [test_res_prometheus.c:metric_register:322]: Testing label collisions 386s [test_res_prometheus.c:metric_register:331]: Testing removal of metrics 386s END /res/prometheus/ - metric_register Time: <1ms Result: PASS 386s START /res/prometheus/ - metric_callback_register 386s [test_res_prometheus.c:metric_callback_register:241]: -> CURLing request... 386s [test_res_prometheus.c:metric_callback_register:250]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 386s # TYPE asterisk_channels_count gauge 386s asterisk_channels_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_sum Total call count. 386s # TYPE asterisk_calls_sum counter 386s asterisk_calls_sum{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_count Current call count. 386s # TYPE asterisk_calls_count gauge 386s asterisk_calls_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_endpoints_count Current endpoint count. 386s # TYPE asterisk_endpoints_count gauge 386s asterisk_endpoints_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_bridges_count Current bridge count. 386s # TYPE asterisk_bridges_count gauge 386s asterisk_bridges_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP test_counter A test counter 386s # TYPE test_counter counter 386s test_counter 0 386s 386s END /res/prometheus/ - metric_callback_register Time: <1ms Result: PASS 386s START /res/prometheus/ - metric_values 386s [test_res_prometheus.c:metric_values:166]: -> CURLing request... 386s [test_res_prometheus.c:metric_values:176]: -> Retrieved: # HELP asterisk_channels_count Current channel count. 386s # TYPE asterisk_channels_count gauge 386s asterisk_channels_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_sum Total call count. 386s # TYPE asterisk_calls_sum counter 386s asterisk_calls_sum{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_calls_count Current call count. 386s # TYPE asterisk_calls_count gauge 386s asterisk_calls_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_endpoints_count Current endpoint count. 386s # TYPE asterisk_endpoints_count gauge 386s asterisk_endpoints_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP asterisk_bridges_count Current bridge count. 386s # TYPE asterisk_bridges_count gauge 386s asterisk_bridges_count{eid="fa:16:3e:78:8c:d1"} 0 386s # HELP test_counter_one A test counter 386s # TYPE test_counter_one counter 386s test_counter_one 1 386s # HELP test_counter_two A test counter 386s # TYPE test_counter_two counter 386s test_counter_two 2 386s 386s END /res/prometheus/ - metric_values Time: <1ms Result: PASS 386s START /res/res_crypto/ - crypto_aes_decrypt 386s [test_crypto.c:crypto_aes_decrypt:607]: Executing AES-ECB decryption test 386s END /res/res_crypto/ - crypto_aes_decrypt Time: 18ms Result: PASS 386s START /res/res_crypto/ - crypto_aes_encrypt 386s [test_crypto.c:crypto_aes_encrypt:531]: Executing AES-ECB encryption test 386s END /res/res_crypto/ - crypto_aes_encrypt Time: 13ms Result: PASS 386s START /res/res_crypto/ - crypto_verify 386s [test_crypto.c:crypto_verify:425]: Executing RSA signature verification test 386s [test_crypto.c:crypto_verify:456]: Couldn't read key: rsa_key1 386s END /res/res_crypto/ - crypto_verify Time: <1ms Result: FAIL 386s START /res/res_crypto/ - crypto_sign 386s [test_crypto.c:crypto_sign:306]: Executing RSA signing test 386s [test_crypto.c:crypto_sign:341]: Couldn't read key: rsa_key1 386s END /res/res_crypto/ - crypto_sign Time: <1ms Result: FAIL 386s START /res/res_crypto/ - crypto_decrypt_pub_key 386s [test_crypto.c:crypto_rsa_decrypt:203]: Executing RSA decryption test 386s [test_crypto.c:crypto_rsa_decrypt:231]: Couldn't read key: rsa_key1 386s END /res/res_crypto/ - crypto_decrypt_pub_key Time: <1ms Result: FAIL 386s START /res/res_crypto/ - crypto_rsa_encrypt 386s [test_crypto.c:crypto_rsa_encrypt:107]: Executing RSA encryption test 386s [test_crypto.c:crypto_rsa_encrypt:138]: Couldn't read key: rsa_key1 386s END /res/res_crypto/ - crypto_rsa_encrypt Time: <1ms Result: FAIL 386s START /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test 386s END /res/res_pjproject/ - ast_sockaddr_from_pj_sockaddr_test Time: <1ms Result: PASS 386s START /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test 386s END /res/res_pjproject/ - ast_sockaddr_to_pj_sockaddr_test Time: <1ms Result: PASS 386s START /res/res_pjsip/ - xml_sanitization_exceeds_buffer 386s END /res/res_pjsip/ - xml_sanitization_exceeds_buffer Time: <1ms Result: PASS 386s START /res/res_pjsip/ - xml_sanitization_end_null 386s END /res/res_pjsip/ - xml_sanitization_end_null Time: <1ms Result: PASS 386s START /res/res_pjsip/scheduler/ - scheduler_policy 386s [test_res_pjsip_scheduler.c:scheduler_policy:355]: This test will take about 4.5 seconds 391s END /res/res_pjsip/scheduler/ - scheduler_policy Time: 4498ms Result: PASS 391s START /res/res_pjsip/scheduler/ - scheduler_cancel 391s [test_res_pjsip_scheduler.c:scheduler_cancel:301]: This test will take about 1.5 seconds 392s END /res/res_pjsip/scheduler/ - scheduler_cancel Time: 1500ms Result: PASS 392s START /res/res_pjsip/scheduler/ - scheduler_cleanup 392s [test_res_pjsip_scheduler.c:scheduler_cleanup:250]: This test will take about 1.6 seconds 394s END /res/res_pjsip/scheduler/ - scheduler_cleanup Time: 1600ms Result: PASS 394s START /res/res_pjsip/scheduler/ - unserialized_scheduler 394s [test_res_pjsip_scheduler.c:scheduler:136]: This test will take about 3.0 seconds 397s END /res/res_pjsip/scheduler/ - unserialized_scheduler Time: 2999ms Result: PASS 397s START /res/res_pjsip/scheduler/ - serialized_scheduler 397s [test_res_pjsip_scheduler.c:scheduler:131]: This test will take about 4.0 seconds 401s END /res/res_pjsip/scheduler/ - serialized_scheduler Time: 3999ms Result: PASS 401s START /res/res_pjsip_pubsub/ - bad_event 401s END /res/res_pjsip_pubsub/ - bad_event Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - loop 401s END /res/res_pjsip_pubsub/ - loop Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - duplicate_resource 401s END /res/res_pjsip_pubsub/ - duplicate_resource Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - bad_branch 401s END /res/res_pjsip_pubsub/ - bad_branch Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - bad_resource 401s END /res/res_pjsip_pubsub/ - bad_resource Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - complex_resource_tree 401s END /res/res_pjsip_pubsub/ - complex_resource_tree Time: <1ms Result: PASS 401s START /res/res_pjsip_pubsub/ - resource_tree 401s END /res/res_pjsip_pubsub/ - resource_tree Time: <1ms Result: PASS 401s START /res/res_pjsip_session/ - merge_refresh_topologies 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5892]: Test 1 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5912]: Test 2 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5936]: Test 3 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5955]: Test 4 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5973]: Test 5 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:5994]: Test 6 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6020]: Test 7 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6041]: Test 8 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6061]: Test 9 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6081]: Test 10 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6104]: Test 11 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6129]: Test 12 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6163]: Test 13 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6187]: Test 14 passed 401s [res_pjsip_session.c:test_resolve_refresh_media_states:6211]: Test 15 passed 401s END /res/res_pjsip_session/ - merge_refresh_topologies Time: <1ms Result: PASS 401s START /res/res_pjsip_session/caps/ - low_level 401s [test_res_pjsip_session_caps.c:low_level:134]: Testing incoming expected pass 401s [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) 401s [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) 401s [test_res_pjsip_session_caps.c:test_create_joint:60]: Testing local: (slin), remote: (all), pref: (local ), outgoing: (no ), expected: (slin) expected result: (PASS) 401s [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) 401s [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) 401s [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) 401s [test_res_pjsip_session_caps.c:low_level:142]: Testing incoming expected fail 401s [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) 401s [test_res_pjsip_session_caps.c:test_create_joint:102]: Expected Failure: Expected: () Actual: (nothing) 401s [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) 401s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 401s [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) 401s [test_res_pjsip_session_caps.c:test_create_joint:81]: Expected Failure: Invalid preference string incoming/outgoing combination. 401s [test_res_pjsip_session_caps.c:low_level:147]: Testing outgoing expected pass 401s [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) 401s [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) 401s [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) 401s [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) 401s [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) 401s [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) 401s [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) 401s END /res/res_pjsip_session/caps/ - low_level Time: 1ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_srv 401s END /res/res_resolver_unbound/ - resolve_srv Time: 3ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_naptr 401s END /res/res_resolver_unbound/ - resolve_naptr Time: <1ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_cancel_off_nominal 401s END /res/res_resolver_unbound/ - resolve_cancel_off_nominal Time: 6ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_async_off_nominal 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query 'duck.feathers', type 1 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query 'goose.feathers', type 28 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query 'goose.feathers', type 1 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query '.1', type 1 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query '.www', type 1 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query '.1', type 12 401s [res_resolver_unbound.c:off_nominal_async_run:1004]: Performing DNS query '.www', type 12 401s END /res/res_resolver_unbound/ - resolve_async_off_nominal Time: <1ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_sync_off_nominal 401s END /res/res_resolver_unbound/ - resolve_sync_off_nominal Time: <1ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_async 401s [res_resolver_unbound.c:nominal_async_run:721]: Performing DNS query 'goose.feathers', type 1 401s [res_resolver_unbound.c:nominal_async_run:721]: Performing DNS query 'goose.feathers', type 28 401s [res_resolver_unbound.c:nominal_async_run:721]: Performing DNS query 'duck.feathers', type 1 401s END /res/res_resolver_unbound/ - resolve_async Time: <1ms Result: PASS 401s START /res/res_resolver_unbound/ - resolve_sync 401s [res_resolver_unbound.c:nominal_sync_run:571]: Performing DNS query 'goose.feathers', type 1 401s [res_resolver_unbound.c:nominal_sync_run:571]: Performing DNS query 'goose.feathers', type 28 401s [res_resolver_unbound.c:nominal_sync_run:571]: Performing DNS query 'duck.feathers', type 1 401s END /res/res_resolver_unbound/ - resolve_sync Time: <1ms Result: PASS 401s START /res/res_rtp/ - fir_nominal 401s END /res/res_rtp/ - fir_nominal Time: <1ms Result: PASS 401s START /res/res_rtp/ - sr_rr_nominal 401s END /res/res_rtp/ - sr_rr_nominal Time: <1ms Result: PASS 401s START /res/res_rtp/ - remb_nominal 401s END /res/res_rtp/ - remb_nominal Time: <1ms Result: PASS 401s START /res/res_rtp/ - lost_packet_stats_nominal 401s END /res/res_rtp/ - lost_packet_stats_nominal Time: <1ms Result: PASS 401s START /res/res_rtp/ - nack_overflow 401s END /res/res_rtp/ - nack_overflow Time: <1ms Result: PASS 401s START /res/res_rtp/ - nack_nominal 401s END /res/res_rtp/ - nack_nominal Time: <1ms Result: PASS 401s START /res/res_rtp/ - nack_no_packet_loss 401s END /res/res_rtp/ - nack_no_packet_loss Time: <1ms Result: PASS 401s START /res/res_sorcery_memory_cache/ - full_backend_cache_stale 416s END /res/res_sorcery_memory_cache/ - full_backend_cache_stale Time: 15000ms Result: PASS 416s START /res/res_sorcery_memory_cache/ - full_backend_cache_expiration 421s END /res/res_sorcery_memory_cache/ - full_backend_cache_expiration Time: 5001ms Result: PASS 421s START /res/res_sorcery_memory_cache/ - expiration 426s END /res/res_sorcery_memory_cache/ - expiration Time: 5000ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - maximum_objects 426s END /res/res_sorcery_memory_cache/ - maximum_objects Time: 4ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - delete 426s END /res/res_sorcery_memory_cache/ - delete Time: <1ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - create 426s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - create 426s END /res/res_sorcery_memory_cache/ - create Time: <1ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - open_with_invalid_options 426s END /res/res_sorcery_memory_cache/ - open_with_invalid_options Time: <1ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - open_with_valid_options 426s END /res/res_sorcery_memory_cache/ - open_with_valid_options Time: <1ms Result: PASS 426s START /res/res_sorcery_memory_cache/ - stale 426s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 0 431s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 1 436s [res_sorcery_memory_cache.c:stale:3189]: Begininning iteration 2 441s END /res/res_sorcery_memory_cache/ - stale Time: 15004ms Result: PASS 441s START /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration 444s END /res/res_sorcery_memory_cache/thrash/ - high_object_count_without_expiration Time: 3028ms Result: PASS 444s START /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale 450s END /res/res_sorcery_memory_cache/thrash/ - conflicting_expire_and_stale Time: 6028ms Result: PASS 450s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale 456s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum_with_expire_and_stale Time: 6018ms Result: PASS 456s START /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum 459s END /res/res_sorcery_memory_cache/thrash/ - unique_objects_exceeding_maximum Time: 3009ms Result: PASS 459s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates 462s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_high_concurrent_updates Time: 3015ms Result: PASS 462s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire 465s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_expire Time: 3028ms Result: PASS 465s START /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale 468s END /res/res_sorcery_memory_cache/thrash/ - low_unique_object_count_immediately_stale Time: 3011ms Result: PASS 468s START /res/sorcery_astdb/ - object_delete_uncreated 468s END /res/sorcery_astdb/ - object_delete_uncreated Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_delete 468s END /res/sorcery_astdb/ - object_delete Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_update_uncreated 468s END /res/sorcery_astdb/ - object_update_uncreated Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_update 468s END /res/sorcery_astdb/ - object_update Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_retrieve_regex 468s END /res/sorcery_astdb/ - object_retrieve_regex Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_retrieve_multiple_field 468s END /res/sorcery_astdb/ - object_retrieve_multiple_field Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_retrieve_multiple_all 468s END /res/sorcery_astdb/ - object_retrieve_multiple_all Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_retrieve_field 468s END /res/sorcery_astdb/ - object_retrieve_field Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_retrieve_id 468s END /res/sorcery_astdb/ - object_retrieve_id Time: <1ms Result: PASS 468s START /res/sorcery_astdb/ - object_create 468s END /res/sorcery_astdb/ - object_create Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_filter 468s END /res/sorcery_realtime/ - object_filter Time: 1ms Result: PASS 468s START /res/sorcery_realtime/ - object_allocate_on_retrieval 468s END /res/sorcery_realtime/ - object_allocate_on_retrieval Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_delete_uncreated 468s END /res/sorcery_realtime/ - object_delete_uncreated Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_delete 468s END /res/sorcery_realtime/ - object_delete Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_update 468s END /res/sorcery_realtime/ - object_update Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_regex_nofetch 468s END /res/sorcery_realtime/ - object_retrieve_regex_nofetch Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_regex 468s END /res/sorcery_realtime/ - object_retrieve_regex Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_multiple_field 468s END /res/sorcery_realtime/ - object_retrieve_multiple_field Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch 468s END /res/sorcery_realtime/ - object_retrieve_multiple_all_nofetch Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_multiple_all 468s END /res/sorcery_realtime/ - object_retrieve_multiple_all Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_field 468s END /res/sorcery_realtime/ - object_retrieve_field Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_retrieve_id 468s END /res/sorcery_realtime/ - object_retrieve_id Time: <1ms Result: PASS 468s START /res/sorcery_realtime/ - object_create 468s END /res/sorcery_realtime/ - object_create Time: <1ms Result: PASS 468s START /res/websocket/ - websocket_client_multiple_protocols 468s END /res/websocket/ - websocket_client_multiple_protocols Time: 2ms Result: PASS 468s START /res/websocket/ - websocket_client_unsupported_protocol 468s END /res/websocket/ - websocket_client_unsupported_protocol Time: <1ms Result: PASS 468s START /res/websocket/ - websocket_client_bad_url 468s END /res/websocket/ - websocket_client_bad_url Time: 1ms Result: PASS 468s START /stasis/channels/ - channel_redirect_snapshot_json 468s END /stasis/channels/ - channel_redirect_snapshot_json Time: <1ms Result: PASS 468s START /stasis/channels/ - channel_snapshot_json 468s END /stasis/channels/ - channel_snapshot_json Time: <1ms Result: PASS 468s START /stasis/channels/ - multi_channel_blob_snapshots 468s END /stasis/channels/ - multi_channel_blob_snapshots Time: <1ms Result: PASS 468s START /stasis/channels/ - multi_channel_blob_create 468s END /stasis/channels/ - multi_channel_blob_create Time: <1ms Result: PASS 468s START /stasis/channels/ - null_blob 468s END /stasis/channels/ - null_blob Time: <1ms Result: PASS 468s START /stasis/channels/ - channel_blob_create 468s END /stasis/channels/ - channel_blob_create Time: <1ms Result: PASS 468s START /stasis/core/ - caching_dtor_order 468s END /stasis/core/ - caching_dtor_order Time: <1ms Result: PASS 468s START /stasis/core/ - dtor_order 468s END /stasis/core/ - dtor_order Time: <1ms Result: PASS 468s START /stasis/core/ - to_ami 468s END /stasis/core/ - to_ami Time: <1ms Result: PASS 468s START /stasis/core/ - no_to_ami 468s END /stasis/core/ - no_to_ami Time: <1ms Result: PASS 468s START /stasis/core/ - to_json 468s END /stasis/core/ - to_json Time: <1ms Result: PASS 468s START /stasis/core/ - no_to_json 468s END /stasis/core/ - no_to_json Time: <1ms Result: PASS 468s START /stasis/core/ - subscription_interleaving 468s END /stasis/core/ - subscription_interleaving Time: <1ms Result: PASS 468s START /stasis/core/ - interleaving 468s END /stasis/core/ - interleaving Time: <1ms Result: PASS 468s START /stasis/core/ - router_cache_updates 468s END /stasis/core/ - router_cache_updates Time: 100ms Result: PASS 468s START /stasis/core/ - router_pool 468s END /stasis/core/ - router_pool Time: <1ms Result: PASS 468s START /stasis/core/ - router 468s END /stasis/core/ - router Time: <1ms Result: PASS 468s START /stasis/core/ - cache_eid_aggregate 468s END /stasis/core/ - cache_eid_aggregate Time: <1ms Result: PASS 468s START /stasis/core/ - cache_dump 468s END /stasis/core/ - cache_dump Time: <1ms Result: PASS 468s START /stasis/core/ - cache 468s END /stasis/core/ - cache Time: <1ms Result: PASS 468s START /stasis/core/ - cache_filter 468s END /stasis/core/ - cache_filter Time: 100ms Result: PASS 468s START /stasis/core/ - forward 468s END /stasis/core/ - forward Time: <1ms Result: PASS 468s START /stasis/core/ - unsubscribe_stops_messages 468s END /stasis/core/ - unsubscribe_stops_messages Time: 100ms Result: PASS 468s START /stasis/core/ - publish_pool 468s END /stasis/core/ - publish_pool Time: <1ms Result: PASS 468s START /stasis/core/ - publish_sync 468s END /stasis/core/ - publish_sync Time: <1ms Result: PASS 468s START /stasis/core/ - publish 468s END /stasis/core/ - publish Time: <1ms Result: PASS 468s START /stasis/core/ - subscription_pool_messages 468s END /stasis/core/ - subscription_pool_messages Time: <1ms Result: PASS 468s START /stasis/core/ - subscription_messages 468s END /stasis/core/ - subscription_messages Time: <1ms Result: PASS 468s START /stasis/core/ - message 468s END /stasis/core/ - message Time: <1ms Result: PASS 468s START /stasis/core/ - message_type 468s END /stasis/core/ - message_type Time: <1ms Result: PASS 468s START /stasis/core/filtering/ - combo_filters 468s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 468s END /stasis/core/filtering/ - combo_filters Time: <1ms Result: PASS 468s START /stasis/core/filtering/ - formatter_filters 468s [test_stasis.c:dump_consumer:2198]: Messages received: 7 Final? yes 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMI Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageJSON Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageAMIEVENT Pass2 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageEVENT Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 468s END /stasis/core/filtering/ - formatter_filters Time: <1ms Result: PASS 468s START /stasis/core/filtering/ - type_filters 468s [test_stasis.c:dump_consumer:2198]: Messages received: 5 Final? yes 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Subscribe 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType1 Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass 468s [test_stasis.c:dump_consumer:2202]: Message type received: TestMessageType2 Pass2 468s [test_stasis.c:dump_consumer:2202]: Message type received: stasis_subscription_change_type Unsubscribe 468s END /stasis/core/filtering/ - type_filters Time: <1ms Result: PASS 468s START /stasis/core/state/ - explicit_publish 468s END /stasis/core/state/ - explicit_publish Time: 42ms Result: PASS 468s START /stasis/core/state/ - implicit_publish 468s END /stasis/core/state/ - implicit_publish Time: 33ms Result: PASS 468s START /stasis/endpoints/ - channel_messages 468s END /stasis/endpoints/ - channel_messages Time: <1ms Result: PASS 468s START /stasis/endpoints/ - cache_clear 468s END /stasis/endpoints/ - cache_clear Time: <1ms Result: PASS 468s START /stasis/endpoints/ - state_changes 468s END /stasis/endpoints/ - state_changes Time: <1ms Result: PASS 468s START /stasis/res/ - app_invoke_dne 468s END /stasis/res/ - app_invoke_dne Time: <1ms Result: PASS 468s START /stasis/res/ - app_invoke_one 468s END /stasis/res/ - app_invoke_one Time: <1ms Result: PASS 468s START /stasis/res/ - app_replaced 468s END /stasis/res/ - app_replaced Time: <1ms Result: PASS 468s 468s 659 Test(s) Executed 655 Passed 4 Failed 468s 'U' option is not compatible with remote console mode and has no effect. 468s 468s Results Generated Successfully: /tmp/autopkgtest.0bBTNd/build.lgJ/src/debian/tests/testmods/output/results.txt 468s 'U' option is not compatible with remote console mode and has no effect. 468s 469s Some test modules were not loaded: 469s 20a21 469s > test_cel.so 469s 53a55 469s > test_message.so 469s Manually disabled: 469s test_message 469s test_cel 469s 469s 'U' option is not compatible with remote console mode and has no effect. 469s 470s autopkgtest [09:08:20]: test asttestmods: -----------------------] 471s asttestmods PASS 471s autopkgtest [09:08:21]: test asttestmods: - - - - - - - - - - results - - - - - - - - - - 471s autopkgtest [09:08:21]: test amr: preparing testbed 540s autopkgtest [09:09:30]: testbed dpkg architecture: ppc64el 540s autopkgtest [09:09:30]: testbed apt version: 2.9.18 540s autopkgtest [09:09:30]: @@@@@@@@@@@@@@@@@@@@ test bed setup 540s autopkgtest [09:09:30]: testbed release detected to be: plucky 541s autopkgtest [09:09:31]: updating testbed package index (apt update) 542s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 542s Get:2 http://ftpmaster.internal/ubuntu plucky InRelease [213 kB] 542s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 542s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 542s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [854 kB] 542s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [10.3 kB] 542s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [9708 B] 542s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [139 kB] 542s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el Packages [260 kB] 542s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/restricted ppc64el Packages [756 B] 542s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/universe ppc64el Packages [982 kB] 542s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse ppc64el Packages [4080 B] 542s Get:13 http://ftpmaster.internal/ubuntu plucky/universe Sources [20.9 MB] 543s Get:14 http://ftpmaster.internal/ubuntu plucky/universe ppc64el Packages [15.3 MB] 548s Fetched 38.7 MB in 6s (5959 kB/s) 549s Reading package lists... 549s + lsb_release --codename --short 549s + RELEASE=plucky 549s + cat 549s + [ plucky != trusty ] 549s + DEBIAN_FRONTEND=noninteractive eatmydata apt-get -y --allow-downgrades -o Dpkg::Options::=--force-confnew dist-upgrade 549s Reading package lists... 550s Building dependency tree... 550s Reading state information... 550s Calculating upgrade... 550s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 550s + rm /etc/apt/preferences.d/force-downgrade-to-release.pref 550s + /usr/lib/apt/apt-helper analyze-pattern ?true 550s + DEBIAN_FRONTEND=noninteractive eatmydata apt-get -y purge --autoremove ?obsolete 550s Reading package lists... 550s Building dependency tree... 550s Reading state information... 551s 0 upgraded, 0 newly installed, 0 to remove and 14 not upgraded. 551s + grep -q trusty /etc/lsb-release 551s + [ ! -d /usr/share/doc/unattended-upgrades ] 551s + [ ! -d /usr/share/doc/lxd ] 551s + [ ! -d /usr/share/doc/lxd-client ] 551s + [ ! -d /usr/share/doc/snapd ] 551s + type iptables 551s + cat 551s + chmod 755 /etc/rc.local 551s + . /etc/rc.local 551s + iptables -w -t mangle -A FORWARD -p tcp --tcp-flags SYN,RST SYN -j TCPMSS --clamp-mss-to-pmtu 551s + iptables -A OUTPUT -d 10.255.255.1/32 -p tcp -j DROP 551s + iptables -A OUTPUT -d 10.255.255.2/32 -p tcp -j DROP 551s + uname -m 551s + [ ppc64le = ppc64le ] 551s + systemctl is-active keyboard-setup.service 551s + [ active = failed ] 551s + [ -d /run/systemd/system ] 551s + systemd-detect-virt --quiet --vm 551s + mkdir -p /etc/systemd/system/systemd-random-seed.service.d/ 551s + cat 551s + grep -q lz4 /etc/initramfs-tools/initramfs.conf 551s + echo COMPRESS=lz4 551s autopkgtest [09:09:41]: upgrading testbed (apt dist-upgrade and autopurge) 551s Reading package lists... 551s Building dependency tree... 551s Reading state information... 552s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 552s Starting 2 pkgProblemResolver with broken count: 0 552s Done 552s Entering ResolveByKeep 552s 553s The following NEW packages will be installed: 553s login.defs 553s The following packages will be upgraded: 553s bsdextrautils bsdutils eject fdisk libblkid1 libfdisk1 libmount1 553s libsmartcols1 libuuid1 login mount passwd util-linux uuid-runtime 553s 14 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 553s Need to get 3680 kB of archives. 553s After this operation, 1376 kB of additional disk space will be used. 553s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el bsdutils ppc64el 1:2.40.2-14ubuntu1 [105 kB] 553s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el eject ppc64el 2.40.2-14ubuntu1 [47.8 kB] 553s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el bsdextrautils ppc64el 2.40.2-14ubuntu1 [92.9 kB] 553s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libfdisk1 ppc64el 2.40.2-14ubuntu1 [188 kB] 553s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el fdisk ppc64el 2.40.2-14ubuntu1 [153 kB] 553s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libblkid1 ppc64el 2.40.2-14ubuntu1 [161 kB] 553s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libmount1 ppc64el 2.40.2-14ubuntu1 [190 kB] 553s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libsmartcols1 ppc64el 2.40.2-14ubuntu1 [108 kB] 553s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el mount ppc64el 2.40.2-14ubuntu1 [146 kB] 553s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el libuuid1 ppc64el 2.40.2-14ubuntu1 [45.3 kB] 553s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el util-linux ppc64el 2.40.2-14ubuntu1 [1176 kB] 553s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el uuid-runtime ppc64el 2.40.2-14ubuntu1 [54.6 kB] 553s Get:13 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el login.defs all 1:4.16.0-7ubuntu1 [38.5 kB] 553s Get:14 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el login ppc64el 1:4.16.0-2+really2.40.2-14ubuntu1 [78.7 kB] 553s Get:15 http://ftpmaster.internal/ubuntu plucky-proposed/main ppc64el passwd ppc64el 1:4.16.0-7ubuntu1 [1094 kB] 554s Fetched 3680 kB in 1s (5125 kB/s) 554s (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 ... 74045 files and directories currently installed.) 554s Preparing to unpack .../bsdutils_1%3a2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking bsdutils (1:2.40.2-14ubuntu1) over (1:2.40.2-1ubuntu2) ... 554s Setting up bsdutils (1:2.40.2-14ubuntu1) ... 554s (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 ... 74045 files and directories currently installed.) 554s Preparing to unpack .../eject_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking eject (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Preparing to unpack .../bsdextrautils_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking bsdextrautils (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Preparing to unpack .../libfdisk1_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking libfdisk1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Preparing to unpack .../fdisk_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking fdisk (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Preparing to unpack .../libblkid1_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking libblkid1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Setting up libblkid1:ppc64el (2.40.2-14ubuntu1) ... 554s (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 ... 74041 files and directories currently installed.) 554s Preparing to unpack .../libmount1_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking libmount1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Setting up libmount1:ppc64el (2.40.2-14ubuntu1) ... 554s (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 ... 74041 files and directories currently installed.) 554s Preparing to unpack .../libsmartcols1_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking libsmartcols1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Setting up libsmartcols1:ppc64el (2.40.2-14ubuntu1) ... 554s (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 ... 74041 files and directories currently installed.) 554s Preparing to unpack .../mount_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking mount (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Preparing to unpack .../libuuid1_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking libuuid1:ppc64el (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Setting up libuuid1:ppc64el (2.40.2-14ubuntu1) ... 554s (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 ... 74041 files and directories currently installed.) 554s Preparing to unpack .../util-linux_2.40.2-14ubuntu1_ppc64el.deb ... 554s Unpacking util-linux (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 554s Setting up util-linux (2.40.2-14ubuntu1) ... 555s fstrim.service is a disabled or a static unit not running, not starting it. 555s (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 ... 74034 files and directories currently installed.) 555s Preparing to unpack .../uuid-runtime_2.40.2-14ubuntu1_ppc64el.deb ... 555s Unpacking uuid-runtime (2.40.2-14ubuntu1) over (2.40.2-1ubuntu2) ... 555s Selecting previously unselected package login.defs. 555s Preparing to unpack .../login.defs_1%3a4.16.0-7ubuntu1_all.deb ... 555s Unpacking login.defs (1:4.16.0-7ubuntu1) ... 555s Replacing files in old package login (1:4.15.3-3ubuntu2) ... 555s Setting up login.defs (1:4.16.0-7ubuntu1) ... 555s Installing new version of config file /etc/login.defs ... 555s (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 ... 74038 files and directories currently installed.) 555s Preparing to unpack .../login_1%3a4.16.0-2+really2.40.2-14ubuntu1_ppc64el.deb ... 555s Unpacking login (1:4.16.0-2+really2.40.2-14ubuntu1) over (1:4.15.3-3ubuntu2) ... 555s Preparing to unpack .../passwd_1%3a4.16.0-7ubuntu1_ppc64el.deb ... 555s Unpacking passwd (1:4.16.0-7ubuntu1) over (1:4.15.3-3ubuntu2) ... 555s Setting up passwd (1:4.16.0-7ubuntu1) ... 556s Setting up bsdextrautils (2.40.2-14ubuntu1) ... 556s Setting up eject (2.40.2-14ubuntu1) ... 556s Setting up libfdisk1:ppc64el (2.40.2-14ubuntu1) ... 556s Setting up mount (2.40.2-14ubuntu1) ... 556s Setting up uuid-runtime (2.40.2-14ubuntu1) ... 556s uuidd.service is a disabled or a static unit not running, not starting it. 556s Setting up login (1:4.16.0-2+really2.40.2-14ubuntu1) ... 556s Setting up fdisk (2.40.2-14ubuntu1) ... 556s Processing triggers for man-db (2.13.0-1) ... 558s Processing triggers for libc-bin (2.40-4ubuntu1) ... 558s Reading package lists... 559s Building dependency tree... 559s Reading state information... 559s Starting pkgProblemResolver with broken count: 0 559s Starting 2 pkgProblemResolver with broken count: 0 559s Done 559s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 559s autopkgtest [09:09:49]: rebooting testbed after setup commands that affected boot 592s Reading package lists... 592s Building dependency tree... 592s Reading state information... 593s Starting pkgProblemResolver with broken count: 0 593s Starting 2 pkgProblemResolver with broken count: 0 593s Done 593s The following NEW packages will be installed: 593s asterisk asterisk-config asterisk-core-sounds-en asterisk-core-sounds-en-gsm 593s asterisk-modules freetds-common libasound2-data libasound2t64 libb64-0d 593s libc-client2007e libcodec2-1.2 libdeflate0 libevent-2.1-7t64 593s libgmime-3.0-0t64 libgsm1 libical3t64 libiksemel3 libjack-jackd2-0 libjbig0 593s libjpeg-turbo8 libjpeg8 libjwt2 liblerc4 libltdl7 liblua5.1-0 libneon27t64 593s libodbc2 libogg0 libopencore-amrnb0 libopencore-amrwb0 libopus0 libopusenc0 593s libopusfile0 libportaudio2 libpq5 libradcli4 libresample1 libsamplerate0 593s libsharpyuv0 libsnmp-base libsnmp40t64 libspandsp2t64 libspeex1 libspeexdsp1 593s libsrtp2-1 libsybdb5 libtiff6 libunbound8 liburiparser1 libvo-amrwbenc0 593s libvorbis0a libvorbisenc2 libvorbisfile3 libwebp7 libxslt1.1 mlock 593s 0 upgraded, 56 newly installed, 0 to remove and 0 not upgraded. 593s Need to get 30.3 MB of archives. 593s After this operation, 95.6 MB of additional disk space will be used. 593s Get:1 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-config all 1:22.1.0~dfsg+~cs6.14.60671435-1 [223 kB] 593s Get:2 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-core-sounds-en-gsm all 1.6.1-1 [2417 kB] 594s Get:3 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-core-sounds-en all 1.6.1-1 [20.6 kB] 594s Get:4 http://ftpmaster.internal/ubuntu plucky/universe ppc64el mlock ppc64el 8:2007f~dfsg-7.1 [8576 B] 594s Get:5 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libc-client2007e ppc64el 8:2007f~dfsg-7.1 [676 kB] 594s Get:6 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libcodec2-1.2 ppc64el 1.2.0-2build1 [9048 kB] 594s Get:7 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libgmime-3.0-0t64 ppc64el 3.2.15+dfsg-1 [205 kB] 594s Get:8 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libgsm1 ppc64el 1.0.22-1build1 [41.9 kB] 594s Get:9 http://ftpmaster.internal/ubuntu plucky/main ppc64el libical3t64 ppc64el 3.0.19-1build1 [346 kB] 594s Get:10 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libiksemel3 ppc64el 1.4-4build2 [34.8 kB] 594s Get:11 http://ftpmaster.internal/ubuntu plucky/main ppc64el libopus0 ppc64el 1.5.2-2 [3038 kB] 594s Get:12 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsamplerate0 ppc64el 0.2.2-4build1 [1348 kB] 594s Get:13 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjack-jackd2-0 ppc64el 1.9.22~dfsg-4 [332 kB] 594s Get:14 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libb64-0d ppc64el 1.2-5build1 [9882 B] 594s Get:15 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libjwt2 ppc64el 1.17.2-1 [20.3 kB] 594s Get:16 http://ftpmaster.internal/ubuntu plucky/universe ppc64el liblua5.1-0 ppc64el 5.1.5-10 [159 kB] 594s Get:17 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libneon27t64 ppc64el 0.34.0-1 [121 kB] 594s Get:18 http://ftpmaster.internal/ubuntu plucky/main ppc64el libltdl7 ppc64el 2.4.7-8 [47.9 kB] 594s Get:19 http://ftpmaster.internal/ubuntu plucky/main ppc64el libodbc2 ppc64el 2.3.12-1ubuntu1 [187 kB] 594s Get:20 http://ftpmaster.internal/ubuntu plucky/main ppc64el libogg0 ppc64el 1.3.5-3build1 [27.6 kB] 594s Get:21 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopencore-amrnb0 ppc64el 0.1.6-1build1 [165 kB] 594s Get:22 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopencore-amrwb0 ppc64el 0.1.6-1build1 [91.2 kB] 595s Get:23 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopusenc0 ppc64el 0.2.1-2build1 [34.5 kB] 595s Get:24 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libopusfile0 ppc64el 0.12-4build3 [60.6 kB] 595s Get:25 http://ftpmaster.internal/ubuntu plucky/main ppc64el libasound2-data all 1.2.12-1 [21.0 kB] 595s Get:26 http://ftpmaster.internal/ubuntu plucky/main ppc64el libasound2t64 ppc64el 1.2.12-1 [493 kB] 595s Get:27 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libportaudio2 ppc64el 19.6.0-1.2build3 [87.5 kB] 595s Get:28 http://ftpmaster.internal/ubuntu plucky/main ppc64el libpq5 ppc64el 17.2-1 [173 kB] 595s Get:29 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libradcli4 ppc64el 1.2.11-1build3 [45.5 kB] 595s Get:30 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libresample1 ppc64el 0.1.3-8 [10.9 kB] 595s Get:31 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsnmp-base all 5.9.4+dfsg-1.1ubuntu5 [206 kB] 595s Get:32 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsnmp40t64 ppc64el 5.9.4+dfsg-1.1ubuntu5 [1171 kB] 595s Get:33 http://ftpmaster.internal/ubuntu plucky/main ppc64el libdeflate0 ppc64el 1.22-1 [63.3 kB] 595s Get:34 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjbig0 ppc64el 2.1-6.1ubuntu2 [35.9 kB] 595s Get:35 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjpeg-turbo8 ppc64el 2.1.5-3ubuntu2 [215 kB] 595s Get:36 http://ftpmaster.internal/ubuntu plucky/main ppc64el libjpeg8 ppc64el 8c-2ubuntu11 [2148 B] 595s Get:37 http://ftpmaster.internal/ubuntu plucky/main ppc64el liblerc4 ppc64el 4.0.0+ds-5ubuntu1 [298 kB] 595s Get:38 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsharpyuv0 ppc64el 1.4.0-0.1 [22.0 kB] 595s Get:39 http://ftpmaster.internal/ubuntu plucky/main ppc64el libwebp7 ppc64el 1.4.0-0.1 [309 kB] 595s Get:40 http://ftpmaster.internal/ubuntu plucky/main ppc64el libtiff6 ppc64el 4.5.1+git230720-4ubuntu4 [272 kB] 595s Get:41 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libspandsp2t64 ppc64el 0.0.6+dfsg-2.1build1 [399 kB] 595s Get:42 http://ftpmaster.internal/ubuntu plucky/main ppc64el libspeex1 ppc64el 1.2.1-3 [108 kB] 595s Get:43 http://ftpmaster.internal/ubuntu plucky/main ppc64el libspeexdsp1 ppc64el 1.2.1-1ubuntu3 [75.0 kB] 595s Get:44 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libsrtp2-1 ppc64el 2.5.0-3build1 [51.4 kB] 595s Get:45 http://ftpmaster.internal/ubuntu plucky/main ppc64el freetds-common all 1.3.17+ds-2build3 [26.9 kB] 595s Get:46 http://ftpmaster.internal/ubuntu plucky/main ppc64el libsybdb5 ppc64el 1.3.17+ds-2build3 [238 kB] 595s Get:47 http://ftpmaster.internal/ubuntu plucky/main ppc64el libevent-2.1-7t64 ppc64el 2.1.12-stable-10 [172 kB] 595s Get:48 http://ftpmaster.internal/ubuntu plucky/main ppc64el libunbound8 ppc64el 1.20.0-1ubuntu2.1 [546 kB] 595s Get:49 http://ftpmaster.internal/ubuntu plucky/universe ppc64el libvo-amrwbenc0 ppc64el 0.1.3-2build1 [126 kB] 595s Get:50 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbis0a ppc64el 1.3.7-2 [142 kB] 595s Get:51 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbisenc2 ppc64el 1.3.7-2 [86.2 kB] 595s Get:52 http://ftpmaster.internal/ubuntu plucky/main ppc64el libvorbisfile3 ppc64el 1.3.7-2 [22.5 kB] 595s Get:53 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk-modules ppc64el 1:22.1.0~dfsg+~cs6.14.60671435-1 [3163 kB] 595s Get:54 http://ftpmaster.internal/ubuntu plucky/universe ppc64el liburiparser1 ppc64el 0.9.8+dfsg-2 [52.7 kB] 595s Get:55 http://ftpmaster.internal/ubuntu plucky/main ppc64el libxslt1.1 ppc64el 1.1.39-0exp1ubuntu2 [191 kB] 595s Get:56 http://ftpmaster.internal/ubuntu plucky/universe ppc64el asterisk ppc64el 1:22.1.0~dfsg+~cs6.14.60671435-1 [2811 kB] 596s Fetched 30.3 MB in 2s (14.1 MB/s) 596s Selecting previously unselected package asterisk-config. 596s (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 ... 74036 files and directories currently installed.) 596s Preparing to unpack .../00-asterisk-config_1%3a22.1.0~dfsg+~cs6.14.60671435-1_all.deb ... 596s Unpacking asterisk-config (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 596s Selecting previously unselected package asterisk-core-sounds-en-gsm. 596s Preparing to unpack .../01-asterisk-core-sounds-en-gsm_1.6.1-1_all.deb ... 596s Unpacking asterisk-core-sounds-en-gsm (1.6.1-1) ... 596s Selecting previously unselected package asterisk-core-sounds-en. 596s Preparing to unpack .../02-asterisk-core-sounds-en_1.6.1-1_all.deb ... 596s Unpacking asterisk-core-sounds-en (1.6.1-1) ... 596s Selecting previously unselected package mlock. 596s Preparing to unpack .../03-mlock_8%3a2007f~dfsg-7.1_ppc64el.deb ... 596s Unpacking mlock (8:2007f~dfsg-7.1) ... 596s Selecting previously unselected package libc-client2007e. 596s Preparing to unpack .../04-libc-client2007e_8%3a2007f~dfsg-7.1_ppc64el.deb ... 596s Unpacking libc-client2007e (8:2007f~dfsg-7.1) ... 596s Selecting previously unselected package libcodec2-1.2:ppc64el. 596s Preparing to unpack .../05-libcodec2-1.2_1.2.0-2build1_ppc64el.deb ... 596s Unpacking libcodec2-1.2:ppc64el (1.2.0-2build1) ... 596s Selecting previously unselected package libgmime-3.0-0t64:ppc64el. 596s Preparing to unpack .../06-libgmime-3.0-0t64_3.2.15+dfsg-1_ppc64el.deb ... 596s Unpacking libgmime-3.0-0t64:ppc64el (3.2.15+dfsg-1) ... 596s Selecting previously unselected package libgsm1:ppc64el. 596s Preparing to unpack .../07-libgsm1_1.0.22-1build1_ppc64el.deb ... 596s Unpacking libgsm1:ppc64el (1.0.22-1build1) ... 596s Selecting previously unselected package libical3t64:ppc64el. 596s Preparing to unpack .../08-libical3t64_3.0.19-1build1_ppc64el.deb ... 596s Unpacking libical3t64:ppc64el (3.0.19-1build1) ... 596s Selecting previously unselected package libiksemel3:ppc64el. 596s Preparing to unpack .../09-libiksemel3_1.4-4build2_ppc64el.deb ... 596s Unpacking libiksemel3:ppc64el (1.4-4build2) ... 596s Selecting previously unselected package libopus0:ppc64el. 596s Preparing to unpack .../10-libopus0_1.5.2-2_ppc64el.deb ... 596s Unpacking libopus0:ppc64el (1.5.2-2) ... 596s Selecting previously unselected package libsamplerate0:ppc64el. 596s Preparing to unpack .../11-libsamplerate0_0.2.2-4build1_ppc64el.deb ... 596s Unpacking libsamplerate0:ppc64el (0.2.2-4build1) ... 596s Selecting previously unselected package libjack-jackd2-0:ppc64el. 596s Preparing to unpack .../12-libjack-jackd2-0_1.9.22~dfsg-4_ppc64el.deb ... 596s Unpacking libjack-jackd2-0:ppc64el (1.9.22~dfsg-4) ... 596s Selecting previously unselected package libb64-0d:ppc64el. 596s Preparing to unpack .../13-libb64-0d_1.2-5build1_ppc64el.deb ... 596s Unpacking libb64-0d:ppc64el (1.2-5build1) ... 596s Selecting previously unselected package libjwt2:ppc64el. 596s Preparing to unpack .../14-libjwt2_1.17.2-1_ppc64el.deb ... 596s Unpacking libjwt2:ppc64el (1.17.2-1) ... 596s Selecting previously unselected package liblua5.1-0:ppc64el. 596s Preparing to unpack .../15-liblua5.1-0_5.1.5-10_ppc64el.deb ... 596s Unpacking liblua5.1-0:ppc64el (5.1.5-10) ... 596s Selecting previously unselected package libneon27t64:ppc64el. 596s Preparing to unpack .../16-libneon27t64_0.34.0-1_ppc64el.deb ... 596s Unpacking libneon27t64:ppc64el (0.34.0-1) ... 596s Selecting previously unselected package libltdl7:ppc64el. 596s Preparing to unpack .../17-libltdl7_2.4.7-8_ppc64el.deb ... 596s Unpacking libltdl7:ppc64el (2.4.7-8) ... 596s Selecting previously unselected package libodbc2:ppc64el. 596s Preparing to unpack .../18-libodbc2_2.3.12-1ubuntu1_ppc64el.deb ... 596s Unpacking libodbc2:ppc64el (2.3.12-1ubuntu1) ... 596s Selecting previously unselected package libogg0:ppc64el. 596s Preparing to unpack .../19-libogg0_1.3.5-3build1_ppc64el.deb ... 596s Unpacking libogg0:ppc64el (1.3.5-3build1) ... 596s Selecting previously unselected package libopencore-amrnb0:ppc64el. 596s Preparing to unpack .../20-libopencore-amrnb0_0.1.6-1build1_ppc64el.deb ... 596s Unpacking libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 596s Selecting previously unselected package libopencore-amrwb0:ppc64el. 597s Preparing to unpack .../21-libopencore-amrwb0_0.1.6-1build1_ppc64el.deb ... 597s Unpacking libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 597s Selecting previously unselected package libopusenc0:ppc64el. 597s Preparing to unpack .../22-libopusenc0_0.2.1-2build1_ppc64el.deb ... 597s Unpacking libopusenc0:ppc64el (0.2.1-2build1) ... 597s Selecting previously unselected package libopusfile0:ppc64el. 597s Preparing to unpack .../23-libopusfile0_0.12-4build3_ppc64el.deb ... 597s Unpacking libopusfile0:ppc64el (0.12-4build3) ... 597s Selecting previously unselected package libasound2-data. 597s Preparing to unpack .../24-libasound2-data_1.2.12-1_all.deb ... 597s Unpacking libasound2-data (1.2.12-1) ... 597s Selecting previously unselected package libasound2t64:ppc64el. 597s Preparing to unpack .../25-libasound2t64_1.2.12-1_ppc64el.deb ... 597s Unpacking libasound2t64:ppc64el (1.2.12-1) ... 597s Selecting previously unselected package libportaudio2:ppc64el. 597s Preparing to unpack .../26-libportaudio2_19.6.0-1.2build3_ppc64el.deb ... 597s Unpacking libportaudio2:ppc64el (19.6.0-1.2build3) ... 597s Selecting previously unselected package libpq5:ppc64el. 597s Preparing to unpack .../27-libpq5_17.2-1_ppc64el.deb ... 597s Unpacking libpq5:ppc64el (17.2-1) ... 597s Selecting previously unselected package libradcli4. 597s Preparing to unpack .../28-libradcli4_1.2.11-1build3_ppc64el.deb ... 597s Unpacking libradcli4 (1.2.11-1build3) ... 597s Selecting previously unselected package libresample1. 597s Preparing to unpack .../29-libresample1_0.1.3-8_ppc64el.deb ... 597s Unpacking libresample1 (0.1.3-8) ... 597s Selecting previously unselected package libsnmp-base. 597s Preparing to unpack .../30-libsnmp-base_5.9.4+dfsg-1.1ubuntu5_all.deb ... 597s Unpacking libsnmp-base (5.9.4+dfsg-1.1ubuntu5) ... 597s Selecting previously unselected package libsnmp40t64:ppc64el. 597s Preparing to unpack .../31-libsnmp40t64_5.9.4+dfsg-1.1ubuntu5_ppc64el.deb ... 597s Unpacking libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu5) ... 597s Selecting previously unselected package libdeflate0:ppc64el. 597s Preparing to unpack .../32-libdeflate0_1.22-1_ppc64el.deb ... 597s Unpacking libdeflate0:ppc64el (1.22-1) ... 597s Selecting previously unselected package libjbig0:ppc64el. 597s Preparing to unpack .../33-libjbig0_2.1-6.1ubuntu2_ppc64el.deb ... 597s Unpacking libjbig0:ppc64el (2.1-6.1ubuntu2) ... 597s Selecting previously unselected package libjpeg-turbo8:ppc64el. 597s Preparing to unpack .../34-libjpeg-turbo8_2.1.5-3ubuntu2_ppc64el.deb ... 597s Unpacking libjpeg-turbo8:ppc64el (2.1.5-3ubuntu2) ... 597s Selecting previously unselected package libjpeg8:ppc64el. 597s Preparing to unpack .../35-libjpeg8_8c-2ubuntu11_ppc64el.deb ... 597s Unpacking libjpeg8:ppc64el (8c-2ubuntu11) ... 597s Selecting previously unselected package liblerc4:ppc64el. 597s Preparing to unpack .../36-liblerc4_4.0.0+ds-5ubuntu1_ppc64el.deb ... 597s Unpacking liblerc4:ppc64el (4.0.0+ds-5ubuntu1) ... 597s Selecting previously unselected package libsharpyuv0:ppc64el. 597s Preparing to unpack .../37-libsharpyuv0_1.4.0-0.1_ppc64el.deb ... 597s Unpacking libsharpyuv0:ppc64el (1.4.0-0.1) ... 597s Selecting previously unselected package libwebp7:ppc64el. 597s Preparing to unpack .../38-libwebp7_1.4.0-0.1_ppc64el.deb ... 597s Unpacking libwebp7:ppc64el (1.4.0-0.1) ... 597s Selecting previously unselected package libtiff6:ppc64el. 597s Preparing to unpack .../39-libtiff6_4.5.1+git230720-4ubuntu4_ppc64el.deb ... 597s Unpacking libtiff6:ppc64el (4.5.1+git230720-4ubuntu4) ... 597s Selecting previously unselected package libspandsp2t64:ppc64el. 597s Preparing to unpack .../40-libspandsp2t64_0.0.6+dfsg-2.1build1_ppc64el.deb ... 597s Unpacking libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 597s Selecting previously unselected package libspeex1:ppc64el. 597s Preparing to unpack .../41-libspeex1_1.2.1-3_ppc64el.deb ... 597s Unpacking libspeex1:ppc64el (1.2.1-3) ... 597s Selecting previously unselected package libspeexdsp1:ppc64el. 597s Preparing to unpack .../42-libspeexdsp1_1.2.1-1ubuntu3_ppc64el.deb ... 597s Unpacking libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 597s Selecting previously unselected package libsrtp2-1:ppc64el. 597s Preparing to unpack .../43-libsrtp2-1_2.5.0-3build1_ppc64el.deb ... 597s Unpacking libsrtp2-1:ppc64el (2.5.0-3build1) ... 597s Selecting previously unselected package freetds-common. 597s Preparing to unpack .../44-freetds-common_1.3.17+ds-2build3_all.deb ... 597s Unpacking freetds-common (1.3.17+ds-2build3) ... 597s Selecting previously unselected package libsybdb5:ppc64el. 597s Preparing to unpack .../45-libsybdb5_1.3.17+ds-2build3_ppc64el.deb ... 597s Unpacking libsybdb5:ppc64el (1.3.17+ds-2build3) ... 597s Selecting previously unselected package libevent-2.1-7t64:ppc64el. 597s Preparing to unpack .../46-libevent-2.1-7t64_2.1.12-stable-10_ppc64el.deb ... 597s Unpacking libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 597s Selecting previously unselected package libunbound8:ppc64el. 597s Preparing to unpack .../47-libunbound8_1.20.0-1ubuntu2.1_ppc64el.deb ... 597s Unpacking libunbound8:ppc64el (1.20.0-1ubuntu2.1) ... 597s Selecting previously unselected package libvo-amrwbenc0:ppc64el. 597s Preparing to unpack .../48-libvo-amrwbenc0_0.1.3-2build1_ppc64el.deb ... 597s Unpacking libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 597s Selecting previously unselected package libvorbis0a:ppc64el. 597s Preparing to unpack .../49-libvorbis0a_1.3.7-2_ppc64el.deb ... 597s Unpacking libvorbis0a:ppc64el (1.3.7-2) ... 597s Selecting previously unselected package libvorbisenc2:ppc64el. 597s Preparing to unpack .../50-libvorbisenc2_1.3.7-2_ppc64el.deb ... 597s Unpacking libvorbisenc2:ppc64el (1.3.7-2) ... 597s Selecting previously unselected package libvorbisfile3:ppc64el. 597s Preparing to unpack .../51-libvorbisfile3_1.3.7-2_ppc64el.deb ... 597s Unpacking libvorbisfile3:ppc64el (1.3.7-2) ... 597s Selecting previously unselected package asterisk-modules. 597s Preparing to unpack .../52-asterisk-modules_1%3a22.1.0~dfsg+~cs6.14.60671435-1_ppc64el.deb ... 597s Unpacking asterisk-modules (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 597s Selecting previously unselected package liburiparser1:ppc64el. 597s Preparing to unpack .../53-liburiparser1_0.9.8+dfsg-2_ppc64el.deb ... 597s Unpacking liburiparser1:ppc64el (0.9.8+dfsg-2) ... 597s Selecting previously unselected package libxslt1.1:ppc64el. 597s Preparing to unpack .../54-libxslt1.1_1.1.39-0exp1ubuntu2_ppc64el.deb ... 597s Unpacking libxslt1.1:ppc64el (1.1.39-0exp1ubuntu2) ... 597s Selecting previously unselected package asterisk. 597s Preparing to unpack .../55-asterisk_1%3a22.1.0~dfsg+~cs6.14.60671435-1_ppc64el.deb ... 597s Unpacking asterisk (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 598s Setting up libsharpyuv0:ppc64el (1.4.0-0.1) ... 598s Setting up libvo-amrwbenc0:ppc64el (0.1.3-2build1) ... 598s Setting up libneon27t64:ppc64el (0.34.0-1) ... 598s Setting up libogg0:ppc64el (1.3.5-3build1) ... 598s Setting up liblerc4:ppc64el (4.0.0+ds-5ubuntu1) ... 598s Setting up libspeex1:ppc64el (1.2.1-3) ... 598s Setting up libgsm1:ppc64el (1.0.22-1build1) ... 598s Setting up asterisk-core-sounds-en-gsm (1.6.1-1) ... 598s Setting up libsnmp-base (5.9.4+dfsg-1.1ubuntu5) ... 598s Setting up libcodec2-1.2:ppc64el (1.2.0-2build1) ... 598s Setting up mlock (8:2007f~dfsg-7.1) ... 598s Setting up libsrtp2-1:ppc64el (2.5.0-3build1) ... 598s Setting up libpq5:ppc64el (17.2-1) ... 598s Setting up libdeflate0:ppc64el (1.22-1) ... 598s Setting up libevent-2.1-7t64:ppc64el (2.1.12-stable-10) ... 598s Setting up libb64-0d:ppc64el (1.2-5build1) ... 598s Setting up libjwt2:ppc64el (1.17.2-1) ... 598s Setting up libjbig0:ppc64el (2.1-6.1ubuntu2) ... 598s Setting up libasound2-data (1.2.12-1) ... 598s Setting up libopencore-amrwb0:ppc64el (0.1.6-1build1) ... 598s Setting up libunbound8:ppc64el (1.20.0-1ubuntu2.1) ... 598s Setting up libasound2t64:ppc64el (1.2.12-1) ... 598s Setting up libradcli4 (1.2.11-1build3) ... 598s Setting up libopus0:ppc64el (1.5.2-2) ... 598s Setting up asterisk-config (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 598s Setting up libvorbis0a:ppc64el (1.3.7-2) ... 598s Setting up libical3t64:ppc64el (3.0.19-1build1) ... 598s Setting up libjpeg-turbo8:ppc64el (2.1.5-3ubuntu2) ... 598s Setting up libltdl7:ppc64el (2.4.7-8) ... 598s Setting up asterisk-core-sounds-en (1.6.1-1) ... 598s update-alternatives: using /usr/share/asterisk/sounds/en_US_f_Allison to provide /usr/share/asterisk/sounds/en (asterisk-prompt-en) in auto mode 598s 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 598s Setting up libwebp7:ppc64el (1.4.0-0.1) ... 598s Setting up libiksemel3:ppc64el (1.4-4build2) ... 598s Setting up libodbc2:ppc64el (2.3.12-1ubuntu1) ... 598s Setting up liburiparser1:ppc64el (0.9.8+dfsg-2) ... 598s Setting up libspeexdsp1:ppc64el (1.2.1-1ubuntu3) ... 598s Setting up liblua5.1-0:ppc64el (5.1.5-10) ... 598s Setting up libxslt1.1:ppc64el (1.1.39-0exp1ubuntu2) ... 598s Setting up libopencore-amrnb0:ppc64el (0.1.6-1build1) ... 598s Setting up libc-client2007e (8:2007f~dfsg-7.1) ... 598s Setting up libresample1 (0.1.3-8) ... 598s Setting up freetds-common (1.3.17+ds-2build3) ... 598s Setting up libgmime-3.0-0t64:ppc64el (3.2.15+dfsg-1) ... 598s Setting up libsamplerate0:ppc64el (0.2.2-4build1) ... 598s Setting up libopusfile0:ppc64el (0.12-4build3) ... 598s Setting up libvorbisenc2:ppc64el (1.3.7-2) ... 598s Setting up libjpeg8:ppc64el (8c-2ubuntu11) ... 598s Setting up libopusenc0:ppc64el (0.2.1-2build1) ... 598s Setting up libsnmp40t64:ppc64el (5.9.4+dfsg-1.1ubuntu5) ... 598s Setting up libsybdb5:ppc64el (1.3.17+ds-2build3) ... 598s Setting up libvorbisfile3:ppc64el (1.3.7-2) ... 598s Setting up libjack-jackd2-0:ppc64el (1.9.22~dfsg-4) ... 598s Setting up libtiff6:ppc64el (4.5.1+git230720-4ubuntu4) ... 598s Setting up libportaudio2:ppc64el (19.6.0-1.2build3) ... 598s Setting up libspandsp2t64:ppc64el (0.0.6+dfsg-2.1build1) ... 598s Setting up asterisk-modules (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 598s Setting up asterisk (1:22.1.0~dfsg+~cs6.14.60671435-1) ... 598s Adding system user for Asterisk 598s info: Adding user `asterisk' to group `dialout' ... 598s info: Adding user `asterisk' to group `audio' ... 599s Created symlink '/etc/systemd/system/multi-user.target.wants/asterisk.service' → '/usr/lib/systemd/system/asterisk.service'. 600s Processing triggers for man-db (2.13.0-1) ... 601s Processing triggers for libc-bin (2.40-4ubuntu1) ... 607s autopkgtest [09:10:37]: test amr: [----------------------- 608s 1 audio amr amr 0 (AMR) 608s 2 audio amrwb amrwb 0 (AMR-WB) 608s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 608s amr - 23000 15000 15000 15000 15000 15000 15000 15000 9000 17000 17000 17000 17000 17000 17000 17000 17000 15000 15000 23000 23000 17250 15000 608s amr amrwb codec2 ulaw alaw gsm g726 g726aal2 adpcm slin8 slin12 slin16 slin24 slin32 slin44 slin48 slin96 slin192 lpc10 speex8 speex16 speex32 g722 opus 608s amrwb 23500 - 23500 23500 23500 23500 23500 23500 23500 17500 17500 9000 17000 17000 17000 17000 17000 17000 23500 23500 15000 23000 15000 14999 608s autopkgtest [09:10:38]: test amr: -----------------------] 608s amr PASS 608s autopkgtest [09:10:38]: test amr: - - - - - - - - - - results - - - - - - - - - - 609s autopkgtest [09:10:39]: @@@@@@@@@@@@@@@@@@@@ summary 609s asttestmods PASS 609s amr PASS 614s nova [W] Using flock in prodstack6-ppc64el 614s Creating nova instance adt-plucky-ppc64el-asterisk-20250114-082527-juju-7f2275-prod-proposed-migration-environment-2-8ac9f10b-f226-4a39-8843-7e04e560acaa from image adt/ubuntu-plucky-ppc64el-server-20250114.img (UUID 06b24e09-b872-4c08-93bb-6c233d059c12)... 614s nova [W] Timed out waiting for 8dea728c-83de-49d0-99ca-17206d8cab3e to get deleted. 614s nova [W] Using flock in prodstack6-ppc64el 614s Creating nova instance adt-plucky-ppc64el-asterisk-20250114-082527-juju-7f2275-prod-proposed-migration-environment-2-8ac9f10b-f226-4a39-8843-7e04e560acaa from image adt/ubuntu-plucky-ppc64el-server-20250114.img (UUID 06b24e09-b872-4c08-93bb-6c233d059c12)... 614s nova [W] Timed out waiting for 6e1ac75f-b40e-46bb-8842-a62635ed69cc to get deleted.